shill: device_info: Postpone cdc_ether device discovery

We test cdc_ether devices at boot to decide whether they
are cellular or plain-Ethernet devices.  The method used
to do so is to figure out if there is a tty device bound
to the same USB host as the cdc_ethernet devices.  With
some systems, however, the tty devices are discovered some
time after the cdc_ether device.  To acommodate this,
postpone calling CreateDevice on such entries to allow
time for device discovery in the kernel to complete.

BUG=chromium-os:31504
TEST=Unit tests; test on physical device.

Change-Id: Ic0e18db6463519f87dde199ee7b804b2010992c6
Reviewed-on: https://gerrit.chromium.org/gerrit/26866
Commit-Ready: Paul Stewart <pstew@chromium.org>
Reviewed-by: Paul Stewart <pstew@chromium.org>
Tested-by: Paul Stewart <pstew@chromium.org>
diff --git a/device_info.cc b/device_info.cc
index 9ee30fb..9cd1d6e 100644
--- a/device_info.cc
+++ b/device_info.cc
@@ -47,6 +47,7 @@
 using base::StringPrintf;
 using base::Unretained;
 using std::map;
+using std::set;
 using std::string;
 using std::vector;
 
@@ -70,6 +71,7 @@
     "GobiNet"
 };
 const char DeviceInfo::kTunDeviceName[] = "/dev/net/tun";
+const int DeviceInfo::kDelayedDeviceCreationSeconds = 5;
 
 DeviceInfo::DeviceInfo(ControlInterface *control_interface,
                        EventDispatcher *dispatcher,
@@ -111,11 +113,14 @@
   link_listener_.reset();
   address_listener_.reset();
   infos_.clear();
+  delayed_devices_callback_.Cancel();
+  delayed_devices_.clear();
 }
 
 void DeviceInfo::RegisterDevice(const DeviceRefPtr &device) {
   SLOG(Device, 2) << __func__ << "(" << device->link_name() << ", "
                   << device->interface_index() << ")";
+  delayed_devices_.erase(device->interface_index());
   CHECK(!GetDevice(device->interface_index()).get());
   infos_[device->interface_index()].device = device;
   if ((device->technology() == Technology::kCellular) ||
@@ -176,8 +181,8 @@
 
   string contents;
   if (!GetDeviceInfoContents(iface_name, kInterfaceUevent, &contents)) {
-    SLOG(Device, 2) << StringPrintf("%s: device %s has no uevent file",
-                                    __func__, iface_name.c_str());
+    LOG(INFO) << StringPrintf("%s: device %s has no uevent file",
+                              __func__, iface_name.c_str());
     return Technology::kUnknown;
   }
 
@@ -251,11 +256,15 @@
 
   // For cdc_ether devices, make sure it's a modem because this driver
   // can be used for other ethernet devices.
-  if (driver_name == kDriverCdcEther &&
-      IsCdcEtherModemDevice(iface_name)) {
-    SLOG(Device, 2) << StringPrintf("%s: device %s is a modem cdc_ether device",
-                                    __func__, iface_name.c_str());
-    return Technology::kCellular;
+  if (driver_name == kDriverCdcEther) {
+    if (IsCdcEtherModemDevice(iface_name)) {
+      LOG(INFO) << StringPrintf("%s: device %s is a modem cdc_ether "
+                                "device", __func__, iface_name.c_str());
+      return Technology::kCellular;
+    }
+    SLOG(Device, 2) << StringPrintf("%s: device %s is a cdc_ether "
+                                    "device", __func__, iface_name.c_str());
+    return Technology::kCDCEthernet;
   }
 
   // Special case for the virtio driver, used when run under KVM. See also
@@ -340,6 +349,7 @@
                                       int interface_index,
                                       Technology::Identifier technology) {
   DeviceRefPtr device;
+  delayed_devices_.erase(interface_index);
 
   switch (technology) {
     case Technology::kCellular:
@@ -398,6 +408,18 @@
                       << " at index " << interface_index;
       rtnl_handler_->SetInterfaceFlags(interface_index, IFF_UP, IFF_UP);
       return NULL;
+    case Technology::kCDCEthernet:
+      // CDCEnternet devices are of indeterminate type when they are
+      // initially created.  Some time later, tty devices may or may
+      // not appear under the same USB device root, which will identify
+      // it as a modem.  Alternatively, ModemManager may discover the
+      // device and create and register a Cellular device.  In either
+      // case, we should delay creating a Device until we can make a
+      // better determination of what type this Device should be.
+      LOG(INFO) << "Delaying creation of device for " << link_name
+                << " at index " << interface_index;
+      DelayDeviceCreation(interface_index);
+      return NULL;
     default:
       // We will not manage this device in shill.  Do not create a device
       // object or do anything to change its state.  We create a stub object
@@ -590,6 +612,7 @@
     }
     indices_.erase(iter->second.name);
     infos_.erase(iter);
+    delayed_devices_.erase(interface_index);
   } else {
     SLOG(Device, 2) << __func__ << ": Unknown device index: "
                     << interface_index;
@@ -647,4 +670,46 @@
   }
 }
 
+void DeviceInfo::DelayDeviceCreation(int interface_index) {
+  delayed_devices_.insert(interface_index);
+  delayed_devices_callback_.Reset(
+      Bind(&DeviceInfo::DelayedDeviceCreationTask, AsWeakPtr()));
+  dispatcher_->PostDelayedTask(delayed_devices_callback_.callback(),
+                               kDelayedDeviceCreationSeconds * 1000);
+}
+
+// Re-evaluate the technology type for each delayed device.
+void DeviceInfo::DelayedDeviceCreationTask() {
+  while (!delayed_devices_.empty()) {
+    set<int>::iterator it = delayed_devices_.begin();
+    int dev_index = *it;
+    delayed_devices_.erase(it);
+
+    DCHECK(ContainsKey(infos_, dev_index));
+    DCHECK(!GetDevice(dev_index));
+
+    const string &link_name = infos_[dev_index].name;
+    Technology::Identifier technology = GetDeviceTechnology(link_name);
+
+    if (technology == Technology::kCDCEthernet) {
+      LOG(INFO) << "In " << __func__ << ": device " << link_name
+                << " is now assumed to be regular Ethernet.";
+      technology = Technology::kEthernet;
+    } else if (technology != Technology::kCellular) {
+      LOG(WARNING) << "In " << __func__ << ": device " << link_name
+                   << " is unexpected technology "
+                   << Technology::NameFromIdentifier(technology);
+    }
+    string address =
+        StringToLowerASCII(infos_[dev_index].mac_address.HexEncode());
+    DCHECK(!address.empty());
+
+    DeviceRefPtr device = CreateDevice(link_name, address, dev_index,
+                                       technology);
+    if (device) {
+      RegisterDevice(device);
+    }
+  }
+}
+
 }  // namespace shill
diff --git a/device_info.h b/device_info.h
index a2de8c5..c3189cd 100644
--- a/device_info.h
+++ b/device_info.h
@@ -11,6 +11,7 @@
 #include <vector>
 
 #include <base/callback.h>
+#include <base/cancelable_callback.h>
 #include <base/file_path.h>
 #include <base/memory/ref_counted.h>
 #include <base/memory/scoped_ptr.h>
@@ -82,6 +83,7 @@
   virtual int GetIndex(const std::string &interface_name) const;
 
  private:
+  friend class DeviceInfoDelayedCreationTest;
   friend class DeviceInfoTechnologyTest;
   friend class DeviceInfoTest;
   FRIEND_TEST(CellularTest, StartLinked);
@@ -127,14 +129,16 @@
   static const char *kModemDrivers[];
   // Path to the tun device.
   static const char kTunDeviceName[];
+  // Time to wait before registering devices which need extra time to detect.
+  static const int kDelayedDeviceCreationSeconds;
 
   // Create a Device object for the interface named |linkname|, with a
   // string-form MAC address |address|, whose kernel interface index
   // is |interface_index| and detected technology is |technology|.
-  DeviceRefPtr CreateDevice(const std::string &link_name,
-                            const std::string &address,
-                            int interface_index,
-                            Technology::Identifier technology);
+  virtual DeviceRefPtr CreateDevice(const std::string &link_name,
+                                    const std::string &address,
+                                    int interface_index,
+                                    Technology::Identifier technology);
 
   // Return the FilePath for a given |path_name| in the device sysinfo for
   // a specific interface |iface_name|.
@@ -155,7 +159,8 @@
                                  FilePath *path_out);
   // Classify the device named |iface_name|, and return an identifier
   // indicating its type.
-  Technology::Identifier GetDeviceTechnology(const std::string &iface_name);
+  virtual Technology::Identifier GetDeviceTechnology(
+      const std::string &iface_name);
   // Checks the device specified by |iface_name| to see if it's a modem device.
   // This method assumes that |iface_name| has already been determined to be
   // using the cdc_ether driver.
@@ -172,7 +177,8 @@
 
   const Info *GetInfo(int interface_index) const;
   void RemoveInfo(int interface_index);
-  void EnableDeviceIPv6Privacy(const std::string &link_name);
+  void DelayDeviceCreation(int interface_index);
+  void DelayedDeviceCreationTask();
 
   ControlInterface *control_interface_;
   EventDispatcher *dispatcher_;
@@ -189,6 +195,9 @@
   std::set<std::string> black_list_;
   FilePath device_info_root_;
 
+  base::CancelableClosure delayed_devices_callback_;
+  std::set<int> delayed_devices_;
+
   // Cache copy of singleton pointers.
   RoutingTable *routing_table_;
   RTNLHandler *rtnl_handler_;
diff --git a/device_info_unittest.cc b/device_info_unittest.cc
index 106d17d..962adb3 100644
--- a/device_info_unittest.cc
+++ b/device_info_unittest.cc
@@ -49,13 +49,15 @@
 
 namespace shill {
 
-class TestEventDispatcher : public EventDispatcher {
+class TestEventDispatcherForDeviceInfo : public EventDispatcher {
  public:
   virtual IOHandler *CreateInputHandler(
       int /*fd*/,
       const Callback<void(InputData*)> &/*callback*/) {
     return NULL;
   }
+  MOCK_METHOD2(PostDelayedTask, bool(const base::Closure &task,
+                                     int64 delay_ms));
 };
 
 class DeviceInfoTest : public Test {
@@ -92,6 +94,13 @@
                                      technology);
   }
 
+  virtual std::set<int> &GetDelayedDevices() {
+    return device_info_.delayed_devices_;
+  }
+
+  int GetDelayedDeviceCreationSeconds() {
+    return DeviceInfo::kDelayedDeviceCreationSeconds * 1000;
+  }
 
  protected:
   static const int kTestDeviceIndex;
@@ -119,7 +128,7 @@
   MockMetrics metrics_;
   StrictMock<MockManager> manager_;
   DeviceInfo device_info_;
-  TestEventDispatcher dispatcher_;
+  TestEventDispatcherForDeviceInfo dispatcher_;
   MockRoutingTable routing_table_;
   StrictMock<MockRTNLHandler> rtnl_handler_;
 };
@@ -384,6 +393,21 @@
       kTestDeviceName, "address", kTestDeviceIndex, Technology::kLoopback));
 }
 
+TEST_F(DeviceInfoTest, CreateDeviceCDCEthernet) {
+  // A cdc_ether device should be postponed to a task.
+  EXPECT_CALL(manager_, modem_info()).Times(0);
+  EXPECT_CALL(routing_table_, FlushRoutes(_)).Times(0);
+  EXPECT_CALL(rtnl_handler_, RemoveInterfaceAddress(_, _)).Times(0);
+  EXPECT_CALL(dispatcher_,
+              PostDelayedTask(_, GetDelayedDeviceCreationSeconds()));
+  EXPECT_TRUE(GetDelayedDevices().empty());
+  EXPECT_FALSE(CreateDevice(
+      kTestDeviceName, "address", kTestDeviceIndex, Technology::kCDCEthernet));
+  EXPECT_FALSE(GetDelayedDevices().empty());
+  EXPECT_EQ(1, GetDelayedDevices().size());
+  EXPECT_EQ(kTestDeviceIndex, *GetDelayedDevices().begin());
+}
+
 TEST_F(DeviceInfoTest, CreateDeviceUnknown) {
   IPAddress address = CreateInterfaceAddress();
 
@@ -686,7 +710,7 @@
 TEST_F(DeviceInfoTechnologyTest, CDCEtherNonModem) {
   CreateInfoSymLink("device", "device_dir");
   CreateInfoSymLink("device_dir/driver", "cdc_ether");
-  EXPECT_EQ(Technology::kEthernet, GetDeviceTechnology());
+  EXPECT_EQ(Technology::kCDCEthernet, GetDeviceTechnology());
 }
 
 TEST_F(DeviceInfoTechnologyTest, PseudoModem) {
@@ -701,4 +725,82 @@
   EXPECT_EQ(Technology::kCellular, GetDeviceTechnology());
 }
 
+class DeviceInfoForDelayedCreationTest : public DeviceInfo {
+ public:
+  DeviceInfoForDelayedCreationTest(ControlInterface *control_interface,
+                                   EventDispatcher *dispatcher,
+                                   Metrics *metrics,
+                                   Manager *manager)
+      : DeviceInfo(control_interface, dispatcher, metrics, manager) {}
+  MOCK_METHOD4(CreateDevice, DeviceRefPtr(const std::string &link_name,
+                                          const std::string &address,
+                                          int interface_index,
+                                          Technology::Identifier technology));
+  MOCK_METHOD1(GetDeviceTechnology,
+               Technology::Identifier(const string &iface_name));
+};
+
+class DeviceInfoDelayedCreationTest : public DeviceInfoTest {
+ public:
+  DeviceInfoDelayedCreationTest()
+      : DeviceInfoTest(),
+        test_device_info_(
+            &control_interface_, &dispatcher_, &metrics_, &manager_) {}
+  virtual ~DeviceInfoDelayedCreationTest() {}
+
+  virtual std::set<int> &GetDelayedDevices() {
+    return test_device_info_.delayed_devices_;
+  }
+
+  void DelayedDeviceCreationTask() {
+    test_device_info_.DelayedDeviceCreationTask();
+  }
+
+  void AddDelayedDevice() {
+    scoped_ptr<RTNLMessage> message(BuildLinkMessage(RTNLMessage::kModeAdd));
+    EXPECT_CALL(test_device_info_, GetDeviceTechnology(kTestDeviceName))
+        .WillOnce(Return(Technology::kCDCEthernet));
+    EXPECT_CALL(test_device_info_, CreateDevice(
+        kTestDeviceName, _, kTestDeviceIndex, Technology::kCDCEthernet))
+        .WillOnce(Return(DeviceRefPtr()));
+    test_device_info_.AddLinkMsgHandler(*message);
+    Mock::VerifyAndClearExpectations(&test_device_info_);
+    // We need to insert the device index ourselves since we have mocked
+    // out CreateDevice.  This insertion is tested in CreateDeviceCDCEthernet
+    // above.
+    GetDelayedDevices().insert(kTestDeviceIndex);
+  }
+
+ protected:
+  DeviceInfoForDelayedCreationTest test_device_info_;
+};
+
+TEST_F(DeviceInfoDelayedCreationTest, NoDevices) {
+  EXPECT_TRUE(GetDelayedDevices().empty());
+  EXPECT_CALL(test_device_info_, GetDeviceTechnology(_)).Times(0);
+  DelayedDeviceCreationTask();
+}
+
+TEST_F(DeviceInfoDelayedCreationTest, EthernetDevice) {
+  AddDelayedDevice();
+  EXPECT_CALL(test_device_info_, GetDeviceTechnology(_))
+      .WillOnce(Return(Technology::kCDCEthernet));
+  EXPECT_CALL(test_device_info_, CreateDevice(
+      kTestDeviceName, _, kTestDeviceIndex, Technology::kEthernet))
+      .WillOnce(Return(DeviceRefPtr()));
+  DelayedDeviceCreationTask();
+  EXPECT_TRUE(GetDelayedDevices().empty());
+}
+
+TEST_F(DeviceInfoDelayedCreationTest, CellularDevice) {
+  AddDelayedDevice();
+  EXPECT_CALL(test_device_info_, GetDeviceTechnology(_))
+      .WillOnce(Return(Technology::kCellular));
+  EXPECT_CALL(test_device_info_, CreateDevice(
+      kTestDeviceName, _, kTestDeviceIndex, Technology::kCellular))
+      .WillOnce(Return(DeviceRefPtr()));
+  DelayedDeviceCreationTask();
+  EXPECT_TRUE(GetDelayedDevices().empty());
+}
+
 }  // namespace shill
diff --git a/technology.h b/technology.h
index 7c01bf9..57a5d2b 100644
--- a/technology.h
+++ b/technology.h
@@ -26,6 +26,7 @@
     kTunnel,
     kBlacklisted,
     kLoopback,
+    kCDCEthernet,  // Only for internal use in DeviceInfo.
     kVirtioEthernet,  // Only for internal use in DeviceInfo.
     kPPP,
     kUnknown,