diff --git a/services/shellchat/src/nettests.rs b/services/shellchat/src/nettests.rs index 9497fcaa7..d634080c0 100644 --- a/services/shellchat/src/nettests.rs +++ b/services/shellchat/src/nettests.rs @@ -103,28 +103,40 @@ pub(crate) fn start_batch_tests() { log::info!("################################################## clone_while_reading"); tt.sleep_ms(PRINT_DELAY).ok(); clone_while_reading(); + + // these tests fail after being called in the long series of tests, but when run on their + // own they pass... + log::info!("################################################## clone_accept_smoke"); + tt.sleep_ms(PRINT_DELAY).ok(); + //netmgr.set_debug_level(log::LevelFilter::Trace); + clone_accept_smoke(); + //netmgr.set_debug_level(log::LevelFilter::Info); + log::info!("################################################## clone_accept_concurrent"); + tt.sleep_ms(PRINT_DELAY).ok(); + //netmgr.set_debug_level(log::LevelFilter::Trace); + clone_accept_concurrent(); + //netmgr.set_debug_level(log::LevelFilter::Info); } - log::info!("################################################## clone_accept_smoke"); - tt.sleep_ms(PRINT_DELAY).ok(); - netmgr.set_debug_level(log::LevelFilter::Trace); - clone_accept_smoke(); - netmgr.set_debug_level(log::LevelFilter::Info); - log::info!("################################################## clone_accept_concurrent"); - tt.sleep_ms(PRINT_DELAY).ok(); - netmgr.set_debug_level(log::LevelFilter::Trace); - clone_accept_concurrent(); - netmgr.set_debug_level(log::LevelFilter::Info); - + // These tests seem to fail unless you insert some debug prints in them. This is a problem + // likely related to race conditions in condvars and ticktimers. We're going to waive this + // for now because the tests themselves are pretty synthetic, it's rare that you create + // multiple sockets simply for the purpose of abandoning them? Or at least, not when + // used as a client; perhaps in a server environment this is common, but Xous isn't targeting + // a server (yet). log::info!("################################################## multiple_connect_serial"); tt.sleep_ms(PRINT_DELAY).ok(); multiple_connect_serial(); log::info!("################################################## multiple_connect_interleaved_greedy_schedule"); tt.sleep_ms(PRINT_DELAY).ok(); + netmgr.set_debug_level(log::LevelFilter::Debug); multiple_connect_interleaved_greedy_schedule(); + netmgr.set_debug_level(log::LevelFilter::Info); log::info!("################################################## multiple_connect_interleaved_lazy_schedule"); tt.sleep_ms(PRINT_DELAY).ok(); + netmgr.set_debug_level(log::LevelFilter::Trace); multiple_connect_interleaved_lazy_schedule(); + netmgr.set_debug_level(log::LevelFilter::Info); log::info!("################################################## FIN"); log::info!("################################################## FIN"); @@ -326,6 +338,7 @@ fn multiple_connect_serial() { fn multiple_connect_interleaved_greedy_schedule() { const MAX: usize = 3; each_ip(&mut |addr| { + log::info!("~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~bind to addr: {:?}", addr); let acceptor = t!(TcpListener::bind(&addr)); let _t = thread::spawn(move || { @@ -333,28 +346,35 @@ fn multiple_connect_interleaved_greedy_schedule() { for (i, stream) in acceptor.incoming().enumerate().take(MAX) { // Start another thread to handle the connection let _t = thread::spawn(move || { + log::info!("++++++++++++++++++++++++++++++++ start thread {}", i); let mut stream = t!(stream); let mut buf = [0]; t!(stream.read(&mut buf)); + log::info!("++++++++++++++++++++++++++++++++ thread {} read: {:?}", i, buf); assert!(buf[0] == i as u8); }); } }); connect(0, addr); + log::info!("~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~after connect(0)"); }); fn connect(i: usize, addr: SocketAddr) { + log::info!("******************************* connect {}", i); if i == MAX { return; } let t = thread::spawn(move || { - let mut stream = t!(TcpStream::connect(&addr)); + log::info!("******************************* connect {:?}", addr); + let mut stream = t!(TcpStream::connect(&addr)); // errors out here // Connect again before writing connect(i + 1, addr); + log::info!("******************************* writing {:?}", i); t!(stream.write(&[i as u8])); }); + log::info!("******************************* joining... {}", i); t.join().ok().expect("thread panicked"); } } @@ -598,18 +618,27 @@ fn clone_while_reading() { fn clone_accept_smoke() { each_ip(&mut |addr| { + log::info!("~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~bind to addr: {:?}", addr); let a = t!(TcpListener::bind(&addr)); + log::info!("~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~bind to addr clone"); let a2 = t!(a.try_clone()); let _t = thread::spawn(move || { + log::info!("++++++++++++++++++++++++++++++++connect #1"); let _ = TcpStream::connect(&addr); + log::info!("++++++++++++++++++++++++++++++++#1 connected"); }); let _t = thread::spawn(move || { + log::info!("--------------------------------connect #2"); let _ = TcpStream::connect(&addr); + log::info!("--------------------------------#2 connected"); }); + log::info!("~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~#1 accept"); t!(a.accept()); + log::info!("~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~#2 accept"); t!(a2.accept()); + log::info!("~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~FINISH"); }) }