[bt][tests] Add better error logging to integration tests
Add more detailed logging to the integration tests, particularly around
initializing the hci emulator driver.
Change-Id: I0eac20b3acd18ff6197a773945edfd21eb28b06a
diff --git a/src/connectivity/bluetooth/lib/fuchsia-bluetooth/src/device_watcher.rs b/src/connectivity/bluetooth/lib/fuchsia-bluetooth/src/device_watcher.rs
index dc40746..437411d 100644
--- a/src/connectivity/bluetooth/lib/fuchsia-bluetooth/src/device_watcher.rs
+++ b/src/connectivity/bluetooth/lib/fuchsia-bluetooth/src/device_watcher.rs
@@ -110,9 +110,11 @@
&'a mut self,
path: &'a Path,
) -> impl Future<Output = Result<(), Error>> + 'a {
+ let path_str = path.display();
let t = self.timeout;
- self.removed_helper(path)
- .on_timeout(t.after_now(), || Err(format_err!("timed out waiting for device")))
+ self.removed_helper(path).on_timeout(t.after_now(), move || {
+ Err(format_err!("timed out waiting for device {}", path_str))
+ })
}
// Private functions:
@@ -157,8 +159,10 @@
events: Vec<WatchEvent>,
) -> impl Future<Output = Result<DeviceFile, Error>> + 'a {
let t = self.timeout;
- self.watch_helper(topo_path, events)
- .on_timeout(t.after_now(), || Err(format_err!("timed out waiting for device")))
+ let path_str = topo_path.display();
+ self.watch_helper(topo_path, events).on_timeout(t.after_now(), move || {
+ Err(format_err!("timed out waiting for device {}", path_str))
+ })
}
// Helper for watching for removal.
@@ -183,7 +187,6 @@
use fidl_fuchsia_device_test::{
DeviceSynchronousProxy, RootDeviceSynchronousProxy, CONTROL_DEVICE,
};
-
fn timeout() -> zx::Duration {
zx::Duration::from_seconds(10)
}
@@ -236,6 +239,9 @@
.expect("Expected to be notified of existing test device");
assert_eq!(dev.path(), found.path());
assert_eq!(dev.topo_path(), found.topo_path());
+
+ // Cleanup after ourselves
+ remove_test_dev(&dev).expect("Failed to remove test device");
}
#[fuchsia_async::run_singlethreaded(test)]
@@ -251,6 +257,9 @@
.expect("Expected to be notified of new test device");
assert_eq!(dev.path(), found.path());
assert_eq!(dev.topo_path(), found.topo_path());
+
+ // Cleanup after ourselves
+ remove_test_dev(&dev).expect("Failed to remove test device");
}
#[fuchsia_async::run_singlethreaded(test)]
diff --git a/src/connectivity/bluetooth/lib/fuchsia-bluetooth/src/hci_emulator.rs b/src/connectivity/bluetooth/lib/fuchsia-bluetooth/src/hci_emulator.rs
index 62d8e99..0d48070 100644
--- a/src/connectivity/bluetooth/lib/fuchsia-bluetooth/src/hci_emulator.rs
+++ b/src/connectivity/bluetooth/lib/fuchsia-bluetooth/src/hci_emulator.rs
@@ -8,7 +8,7 @@
device_watcher::{DeviceFile, DeviceWatcher, WatchFilter},
util::open_rdwr,
},
- anyhow::{format_err, Error},
+ anyhow::{format_err, Context, Error},
fidl_fuchsia_bluetooth_test::{EmulatorSettings, HciEmulatorProxy},
fidl_fuchsia_device::ControllerProxy,
fidl_fuchsia_device_test::{DeviceProxy, RootDeviceProxy, CONTROL_DEVICE, MAX_DEVICE_NAME_LEN},
@@ -54,8 +54,13 @@
/// will be published; to do so it must be explicitly configured and created with a call to
/// `publish()`
pub async fn create(name: &str) -> Result<Emulator, Error> {
- let dev = TestDevice::create(name).await?;
- let emulator = dev.bind().await?;
+ let dev = TestDevice::create(name)
+ .await
+ .context(format!("Error creating hci-emulator test device '{}'", name))?;
+ let emulator = dev
+ .bind()
+ .await
+ .context(format!("Error binding hci-emulator test device '{}'", name))?;
Ok(Emulator { dev: Some(dev), emulator: emulator })
}
@@ -135,7 +140,8 @@
}
// Connect to the test control device and obtain a channel to the RootDevice capability.
- let control_dev = open_rdwr(CONTROL_DEVICE)?;
+ let control_dev =
+ open_rdwr(CONTROL_DEVICE).context(format!("Error opening file {}", CONTROL_DEVICE))?;
let root_device = RootDeviceProxy::new(fasync::Channel::from_channel(
fdio::clone_channel(&control_dev)?,
)?);
@@ -150,7 +156,7 @@
Err(format_err!("timed out waiting to create bt-hci-emulator device {}", name))
})
.await?;
- zx::Status::ok(status)?;
+ zx::Status::ok(status).context(format!("Error creating test device '{}'", name))?;
Ok(TestDevice(fdio::create_fd(zx::Handle::from(local))?))
}
diff --git a/src/connectivity/bluetooth/tests/integration/src/harness/host_driver.rs b/src/connectivity/bluetooth/tests/integration/src/harness/host_driver.rs
index a34bc79a..07930f2 100644
--- a/src/connectivity/bluetooth/tests/integration/src/harness/host_driver.rs
+++ b/src/connectivity/bluetooth/tests/integration/src/harness/host_driver.rs
@@ -3,7 +3,7 @@
// found in the LICENSE file.
use {
- anyhow::Error,
+ anyhow::{Context, Error},
fidl_fuchsia_bluetooth_host::HostProxy,
fidl_fuchsia_bluetooth_test::HciEmulatorProxy,
fuchsia_async as fasync,
@@ -173,14 +173,28 @@
// Creates a fake bt-hci device and returns the corresponding bt-host device once it gets created.
async fn new_host_harness() -> Result<(HostDriverHarness, Emulator), Error> {
- let emulator = Emulator::create("bt-integration-test-host").await?;
- let host_dev = emulator.publish_and_wait_for_host(Emulator::default_settings()).await?;
+ let emulator = Emulator::create("bt-integration-test-host")
+ .await
+ .context("Error creating emulator root device")?;
+ let host_dev = emulator
+ .publish_and_wait_for_host(Emulator::default_settings())
+ .await
+ .context("Error publishing emulator hci device")?;
// Open a Host FIDL interface channel to the bt-host device.
- let fidl_handle = host::open_host_channel(&host_dev.file())?;
- let host_proxy = HostProxy::new(fasync::Channel::from_channel(fidl_handle.into())?);
+ let fidl_handle =
+ host::open_host_channel(&host_dev.file()).context("Error opening host device file")?;
+ let host_proxy = HostProxy::new(
+ fasync::Channel::from_channel(fidl_handle.into())
+ .context("Error creating async channel from host device")?,
+ );
- let host_info = host_proxy.watch_state().await?.try_into()?;
+ let host_info = host_proxy
+ .watch_state()
+ .await
+ .context("Error calling WatchState()")?
+ .try_into()
+ .context("Invalid HostInfo received")?;
let host_path = host_dev.path().to_path_buf();
let peers = HashMap::new();
diff --git a/src/connectivity/bluetooth/tests/integration/src/harness/host_watcher.rs b/src/connectivity/bluetooth/tests/integration/src/harness/host_watcher.rs
index 089454c..f1ecd2f 100644
--- a/src/connectivity/bluetooth/tests/integration/src/harness/host_watcher.rs
+++ b/src/connectivity/bluetooth/tests/integration/src/harness/host_watcher.rs
@@ -9,7 +9,6 @@
expectation::asynchronous::{ExpectableState, ExpectationHarness},
types::{HostId, HostInfo},
},
- fuchsia_syslog::fx_log_info,
futures::future::{self, BoxFuture, FutureExt},
std::{collections::HashMap, convert::TryFrom},
};
@@ -27,9 +26,7 @@
async fn watch_hosts(harness: HostWatcherHarness) -> Result<(), Error> {
let proxy = harness.aux().clone();
loop {
- fx_log_info!("Calling HostWatcher.Watch()");
let hosts = proxy.watch().await?;
- fx_log_info!("Hosts updated: {:?}", hosts);
let hosts: Result<HashMap<HostId, HostInfo>, Error> = hosts
.into_iter()
.map(|info| {
diff --git a/src/connectivity/bluetooth/tests/integration/src/harness/mod.rs b/src/connectivity/bluetooth/tests/integration/src/harness/mod.rs
index 8df543a..cd02f33 100644
--- a/src/connectivity/bluetooth/tests/integration/src/harness/mod.rs
+++ b/src/connectivity/bluetooth/tests/integration/src/harness/mod.rs
@@ -87,7 +87,7 @@
fx_log_info!("[ RUN ] {}...", name);
let result = executor.run_singlethreaded(run_with_harness(test));
if let Err(err) = &result {
- fx_log_err!("[ \x1b[31mFAILED\x1b[0m ] {}: Error running test: {}", name, err);
+ fx_log_err!("[ \x1b[31mFAILED\x1b[0m ] {}: Error running test: {:?}", name, err);
} else {
fx_log_info!("[ \x1b[32mPASSED\x1b[0m ] {}", name);
}
