Attempt to make systemtests more reliable

By always reading both stdout and stderr in case one fills its pipe and stalls. Wonder whether we'd be better off using probe-rs as an in-process library rather than shelling out to it?
pdh11 · Jul 9, 2024 · 03ab2af · 03ab2af
1 parent 8f05cae
commit 03ab2af
Show file tree

Hide file tree

Showing 6 changed files with 48 additions and 29 deletions.
diff --git a/cross/rp2040-w5500/src/bin/rp2040-w5500macraw-ssdp-rtic.rs b/cross/rp2040-w5500/src/bin/rp2040-w5500macraw-ssdp-rtic.rs
@@ -321,7 +321,7 @@ mod app {
                 &ws,
             );
 
-            ssdp.subscribe("ssdp:all".to_string(), Listener {}, &ws);
+            ssdp.subscribe("cotton-test-server-rp2040".to_string(), Listener {}, &ws);
 
             defmt::println!("Advertising!");
             ssdp.advertise(

diff --git a/cross/stm32f746-nucleo/src/bin/stm32f746-nucleo-ssdp-rtic.rs b/cross/stm32f746-nucleo/src/bin/stm32f746-nucleo-ssdp-rtic.rs
@@ -140,7 +140,7 @@ mod app {
             );
             let ws = WrappedSocket::new(&mut udp_socket);
             _ = ssdp.on_network_event(&ev, &wi, &ws);
-            ssdp.subscribe("ssdp:all".to_string(), Listener {}, &ws);
+            ssdp.subscribe("cotton-test-server-stm32f746".to_string(), Listener {}, &ws);
 
             let uuid = alloc::format!(
                 "{:032x}",

diff --git a/systemtests/tests/device/device_test.rs b/systemtests/tests/device/device_test.rs
@@ -15,6 +15,24 @@ struct DeviceTestInner {
     errors: String,
 }
 
+impl DeviceTestInner {
+    fn poll(&mut self) {
+        let mut s = String::new();
+        self.stdout.read_available_to_string(&mut s).unwrap();
+        self.output.push_str(&s);
+        if !s.is_empty() {
+            eprintln!("{:?}: stdout {s}", Instant::now());
+        }
+
+        let mut s = String::new();
+        self.stderr.read_available_to_string(&mut s).unwrap();
+        self.errors.push_str(&s);
+        if !s.is_empty() {
+            eprintln!("{:?}: stderr {s}", Instant::now());
+        }
+    }
+}
+
 pub struct DeviceTest {
     inner: Mutex<DeviceTestInner>,
 }
@@ -60,14 +78,12 @@ impl DeviceTest {
 
     pub fn expect(&self, needle: &str, timeout: Duration) {
         let start = Instant::now();
+        eprintln!("{:?}: searching stdout for {needle}", Instant::now());
 
         loop {
             {
                 let mut inner = self.inner.lock().unwrap();
-                let mut s = String::new();
-                inner.stdout.read_available_to_string(&mut s).unwrap();
-                inner.output.push_str(&s);
-                print!("{s}");
+                inner.poll();
                 if let Some((_before, after)) = inner.output.split_once(needle)
                 {
                     eprintln!("OK: {needle}");
@@ -76,6 +92,7 @@ impl DeviceTest {
                 }
 
                 if start.elapsed() > timeout {
+                    eprintln!("{:?}: stdout {}", Instant::now(), inner.output);
                     assert_contains!(inner.output, needle);
                     return;
                 }
@@ -86,22 +103,21 @@ impl DeviceTest {
 
     pub fn expect_stderr(&self, needle: &str, timeout: Duration) {
         let start = Instant::now();
+        eprintln!("{:?}: searching stderr for {needle}", Instant::now());
 
         loop {
             {
                 let mut inner = self.inner.lock().unwrap();
-                let mut s = String::new();
-                inner.stderr.read_available_to_string(&mut s).unwrap();
-                inner.errors.push_str(&s);
-                print!("{s}");
-                if let Some((_before, after)) = inner.output.split_once(needle)
+                inner.poll();
+                if let Some((_before, after)) = inner.errors.split_once(needle)
                 {
                     eprintln!("OK: {needle}");
-                    inner.output = after.to_string();
+                    inner.errors = after.to_string();
                     return;
                 }
 
                 if start.elapsed() > timeout {
+                    eprintln!("{:?}: stderr {}", Instant::now(), inner.errors);
                     assert_contains!(inner.errors, needle);
                     return;
                 }

diff --git a/systemtests/tests/device/rp2040_w5500.rs b/systemtests/tests/device/rp2040_w5500.rs
@@ -14,7 +14,7 @@ fn rp2040_test<F: FnOnce(DeviceTest) -> () + panic::UnwindSafe>(
 #[test]
 #[serial(rp2040_w5500)]
 #[cfg_attr(miri, ignore)]
-fn arm_rp2040_w5500_hello() {
+fn arm_rp2040_w5500_0hello() {
     rp2040_test(
         "../cross/rp2040-w5500/target/thumbv6m-none-eabi/debug/hello",
         |t| {
@@ -59,7 +59,8 @@ fn arm_rp2040_w5500macraw_ssdp_rtic() {
             nt.expect_stderr("Finished in", Duration::from_secs(45));
             nt.expect("DHCP config acquired!", Duration::from_secs(10));
             ssdp_test(
-                Some("cotton-test-server-rp2040".to_string()),
+                "cotton-test-server-rp2040",
+                "rp2040-w5500-test",
                 |st| {
                     nt.expect("SSDP! cotton-test-server-rp2040",
                               Duration::from_secs(20));

diff --git a/systemtests/tests/device/ssdp_test.rs b/systemtests/tests/device/ssdp_test.rs
@@ -20,6 +20,7 @@ impl SsdpTest {
 
     pub fn expect_seen(&self, notification_type: &str, timeout: Duration) {
         let start = Instant::now();
+        eprintln!("{:?}: Looking for {notification_type}", Instant::now());
 
         loop {
             {
@@ -28,6 +29,7 @@ impl SsdpTest {
                     return;
                 }
                 if start.elapsed() > timeout {
+                    eprintln!("{:?}: Didn't find it", Instant::now());
                     assert_contains!(v, notification_type);
                     return;
                 }
@@ -39,7 +41,8 @@ impl SsdpTest {
 }
 
 pub fn ssdp_test<F: FnOnce(SsdpTest) -> () + panic::UnwindSafe>(
-    advertise: Option<String>,
+    my_service: &'static str,
+    device_service: &'static str,
     f: F,
 ) {
     let t = SsdpTest::new();
@@ -58,19 +61,17 @@ pub fn ssdp_test<F: FnOnce(SsdpTest) -> () + panic::UnwindSafe>(
                 Service::new(poll.registry(), (SSDP_TOKEN1, SSDP_TOKEN2))
                     .unwrap();
 
-            if let Some(nt) = advertise {
-                let uuid = uuid::Uuid::new_v4();
-                ssdp.advertise(
-                    uuid.to_string(),
-                    cotton_ssdp::Advertisement {
-                        notification_type: nt.to_string(),
-                        location: "http://127.0.0.1/test".to_string(),
-                    },
-                );
-            }
+            let uuid = uuid::Uuid::new_v4();
+            ssdp.advertise(
+                uuid.to_string(),
+                cotton_ssdp::Advertisement {
+                    notification_type: my_service.to_string(),
+                    location: "http://127.0.0.1/test".to_string(),
+                },
+            );
 
             ssdp.subscribe(
-                "ssdp:all",
+                device_service,
                 Box::new(move |r| {
                     println!("HOST GOT {r:?}");
                     if let cotton_ssdp::Notification::Alive {

diff --git a/systemtests/tests/device/stm32f746_nucleo.rs b/systemtests/tests/device/stm32f746_nucleo.rs
@@ -19,7 +19,7 @@ fn nucleo_test<F: FnOnce(DeviceTest) -> () + panic::UnwindSafe>(
 #[test]
 #[serial(stm32f746_nucleo)]
 #[cfg_attr(miri, ignore)]
-fn arm_stm32f746_nucleo_hello() {
+fn arm_stm32f746_nucleo_0hello() {
     nucleo_test(
         "../cross/stm32f746-nucleo/target/thumbv7em-none-eabi/debug/stm32f746-nucleo-hello",
         |t| {
@@ -51,12 +51,13 @@ fn arm_stm32f746_nucleo_ssdp() {
             nt.expect_stderr("Finished in", Duration::from_secs(45));
             nt.expect("DHCP config acquired!", Duration::from_secs(10));
             ssdp_test(
-                Some("cotton-test-server-stm32f746".to_string()),
+                "cotton-test-server-stm32f746",  // host service
+                "stm32f746-nucleo-test", // device service
                 |st| {
                     nt.expect("SSDP! cotton-test-server-stm32f746",
                               Duration::from_secs(20));
                     st.expect_seen("stm32f746-nucleo-test",
-                              Duration::from_secs(10));
+                              Duration::from_secs(20));
                 }
             );
         }