oxedyne/fe2o3/fe2o3_o3db_sync/tests/control_wait.rs
10.1 KiB, 1 run
created by r1870400018:35241, which is this file's identity for as long as the history lasts, whatever it is later renamed to
download · who wrote it · its history
| 1 | //! Regression tests for the deadline a control operation is held to. |
| 2 | //! |
| 3 | //! `OzoneApi::activate_gc` used to wait `constant::USER_REQUEST_WAIT`, six |
| 4 | //! seconds, for every zone bot to acknowledge. Activation is issued once, at |
| 5 | //! startup, and its message queues behind whatever initialisation the zone bots |
| 6 | //! are still doing, so on a 2.6 GB store none of them answered in time and the |
| 7 | //! database could not be brought up at all. A user request deadline was being |
| 8 | //! applied to a startup control operation. |
| 9 | //! |
| 10 | //! The zone bots are stood in for here by threads that hold a control message |
| 11 | //! for longer than `USER_REQUEST_TIMEOUT` before acknowledging it, which is the |
| 12 | //! condition the real store produced. The database itself is not started: the |
| 13 | //! channels are real, the api is real, and only what sits on the far end of them |
| 14 | //! is fabricated, so nothing has to be made big and slow to reproduce a bot that |
| 15 | //! is busy. |
| 16 | //! |
| 17 | //! [Written with AI entirely](https://need2know.ai/entirely-ai/code)\ |
| 18 | //! Anthropic Claude |
| 19 | |
| 20 | use oxedyne_fe2o3_core::{ |
| 21 | prelude::*, |
| 22 | channels::Recv, |
| 23 | rand::RanDef, |
| 24 | }; |
| 25 | use oxedyne_fe2o3_crypto::enc::EncryptionScheme; |
| 26 | use oxedyne_fe2o3_hash::{ |
| 27 | csum::ChecksumScheme, |
| 28 | hash::HashScheme, |
| 29 | }; |
| 30 | use oxedyne_fe2o3_iop_db::api::ScanOpts; |
| 31 | use oxedyne_fe2o3_o3db_sync::{ |
| 32 | api::OzoneApi, |
| 33 | base::{ |
| 34 | cfg::OzoneConfig, |
| 35 | constant, |
| 36 | id::{ |
| 37 | Bid, |
| 38 | OzoneBotId, |
| 39 | }, |
| 40 | index::ZoneInd, |
| 41 | }, |
| 42 | bots::worker::bot::WorkerType, |
| 43 | comm::{ |
| 44 | channels::BotChannels, |
| 45 | msg::OzoneMsg, |
| 46 | response::Wait, |
| 47 | }, |
| 48 | data::core::RestSchemes, |
| 49 | test::setup, |
| 50 | }; |
| 51 | |
| 52 | use std::{ |
| 53 | path::PathBuf, |
| 54 | sync::{ |
| 55 | Arc, |
| 56 | atomic::{ |
| 57 | AtomicBool, |
| 58 | Ordering, |
| 59 | }, |
| 60 | }, |
| 61 | thread, |
| 62 | time::{ |
| 63 | Duration, |
| 64 | Instant, |
| 65 | }, |
| 66 | }; |
| 67 | |
| 68 | type Api = OzoneApi< |
| 69 | { setup::UID_LEN }, |
| 70 | setup::Uid, |
| 71 | EncryptionScheme, |
| 72 | HashScheme, |
| 73 | HashScheme, |
| 74 | ChecksumScheme, |
| 75 | >; |
| 76 | |
| 77 | type Chans = BotChannels< |
| 78 | { setup::UID_LEN }, |
| 79 | setup::Uid, |
| 80 | EncryptionScheme, |
| 81 | HashScheme, |
| 82 | >; |
| 83 | |
| 84 | // How long a stand-in bot holds a message before acknowledging it. It must exceed |
| 85 | // USER_REQUEST_TIMEOUT, since the whole point is a bot that a user request deadline |
| 86 | // would abandon, and stay well inside CONTROL_REQUEST_TIMEOUT. |
| 87 | const BUSY: Duration = Duration::from_secs(8); |
| 88 | // Ceiling on how long a call bounded by USER_REQUEST_TIMEOUT may take before its |
| 89 | // deadline is not the one it claims. Below BUSY, so a call that waited for the bot |
| 90 | // cannot pass. |
| 91 | const USER_DEADLINE_CEILING: Duration = Duration::from_secs(7); |
| 92 | |
| 93 | #[test] |
| 94 | fn main() -> Outcome<()> { |
| 95 | log_set_level!("warn"); |
| 96 | let outcome = run(); |
| 97 | log_finish_wait!(); |
| 98 | outcome |
| 99 | } |
| 100 | |
| 101 | fn run() -> Outcome<()> { |
| 102 | res!(busy_zone_bots_do_not_defeat_gc_activation()); |
| 103 | res!(a_request_path_scan_keeps_the_short_deadline()); |
| 104 | res!(a_deliberate_walk_can_ask_for_longer()); |
| 105 | Ok(()) |
| 106 | } |
| 107 | |
| 108 | /// Channels and an api with no bots behind them, so that the tests can play the bots. |
| 109 | fn harness(nz: u16) -> Outcome<(Api, Chans)> { |
| 110 | let mut cfg = res!(setup::default_cfg()); |
| 111 | cfg.num_zones = nz; |
| 112 | cfg.num_scbots_per_zone = 1; |
| 113 | cfg.num_wbots_per_zone = 1; |
| 114 | // The zone overrides in the shared test config name directories this test never |
| 115 | // touches, and a stale one would only confuse a failure message. |
| 116 | cfg.zone_overrides = OzoneConfig::default().zone_overrides; |
| 117 | let chans = Chans::new(&cfg); |
| 118 | let api = Api::new( |
| 119 | OzoneBotId::Master(Bid::randef()), |
| 120 | PathBuf::from("."), |
| 121 | cfg, |
| 122 | chans.clone(), |
| 123 | RestSchemes::default(), |
| 124 | ); |
| 125 | Ok((api, chans)) |
| 126 | } |
| 127 | |
| 128 | /// A stand-in supervisor and its zone bots: forwards nothing, holds the control message |
| 129 | /// for `BUSY`, then acknowledges once per zone, exactly as `nz` busy zone bots would. |
| 130 | fn busy_supervisor(chans: &Chans, nz: usize, stop: Arc<AtomicBool>) -> thread::JoinHandle<()> { |
| 131 | let sup = chans.sup().clone(); |
| 132 | thread::spawn(move || { |
| 133 | while !stop.load(Ordering::Relaxed) { |
| 134 | match sup.recv_timeout(constant::CHECK_INTERVAL) { |
| 135 | Recv::Empty => continue, |
| 136 | Recv::Result(Err(_)) => return, |
| 137 | Recv::Result(Ok(msg)) => { |
| 138 | let resp = match msg { |
| 139 | OzoneMsg::GcControl(_, resp) => resp, |
| 140 | OzoneMsg::NewLiveFile(_, resp) => resp, |
| 141 | _ => continue, |
| 142 | }; |
| 143 | thread::sleep(BUSY); |
| 144 | for _ in 0..nz { |
| 145 | if resp.send(OzoneMsg::Ok).is_err() { return; } |
| 146 | } |
| 147 | }, |
| 148 | } |
| 149 | } |
| 150 | }) |
| 151 | } |
| 152 | |
| 153 | /// A stand-in scan bot for one zone: every walk it is asked for costs `BUSY`, which is |
| 154 | /// what a walk of a large store costs. |
| 155 | fn busy_scan_bot( |
| 156 | chans: &Chans, |
| 157 | z: usize, |
| 158 | stop: Arc<AtomicBool>, |
| 159 | ) |
| 160 | -> Outcome<thread::JoinHandle<()>> |
| 161 | { |
| 162 | let pool = res!(chans.get_workers_of_type_in_zone(&WorkerType::Scan, &ZoneInd::new(z))); |
| 163 | let bot = res!(pool.get_bot(0)).clone(); |
| 164 | Ok(thread::spawn(move || { |
| 165 | while !stop.load(Ordering::Relaxed) { |
| 166 | match bot.recv_timeout(constant::CHECK_INTERVAL) { |
| 167 | Recv::Empty => continue, |
| 168 | Recv::Result(Err(_)) => return, |
| 169 | Recv::Result(Ok(OzoneMsg::ScanRequest { resp, .. })) => { |
| 170 | thread::sleep(BUSY); |
| 171 | if resp.send(OzoneMsg::ScanEntries(Vec::new())).is_err() { return; } |
| 172 | }, |
| 173 | Recv::Result(Ok(_)) => continue, |
| 174 | } |
| 175 | } |
| 176 | })) |
| 177 | } |
| 178 | |
| 179 | /// Zone bots still busy at startup must not defeat activation, which is what the six |
| 180 | /// second user request deadline made them do. |
| 181 | fn busy_zone_bots_do_not_defeat_gc_activation() -> Outcome<()> { |
| 182 | let nz = 2usize; |
| 183 | let (api, chans) = res!(harness(nz as u16)); |
| 184 | let stop = Arc::new(AtomicBool::new(false)); |
| 185 | let handle = busy_supervisor(&chans, nz, stop.clone()); |
| 186 | |
| 187 | let t0 = Instant::now(); |
| 188 | let result = api.activate_gc(true); |
| 189 | let took = t0.elapsed(); |
| 190 | |
| 191 | stop.store(true, Ordering::Relaxed); |
| 192 | let _ = handle.join(); |
| 193 | |
| 194 | if let Err(e) = result { |
| 195 | return Err(err!(e, |
| 196 | "Activation was defeated by zone bots busy for {:?}, after {:?}. \ |
| 197 | Activation is a control operation and must wait \ |
| 198 | constant::CONTROL_REQUEST_TIMEOUT ({:?}), not a user request deadline.", |
| 199 | BUSY, took, constant::CONTROL_REQUEST_TIMEOUT; |
| 200 | Test)); |
| 201 | } |
| 202 | // A pass that did not actually outlast the busy period would mean the stand-in bots |
| 203 | // never held the message, and so would prove nothing. |
| 204 | if took < BUSY { |
| 205 | return Err(err!( |
| 206 | "Activation returned after {:?}, sooner than the {:?} the stand-in zone bots \ |
| 207 | were busy for, so the wait was never tested.", took, BUSY; |
| 208 | Test, Invalid)); |
| 209 | } |
| 210 | Ok(()) |
| 211 | } |
| 212 | |
| 213 | /// A scan is a walk of every index file in every zone, and the short deadline on the |
| 214 | /// request path is what keeps that off it. Lengthening the control deadline must not |
| 215 | /// have lengthened this one. |
| 216 | fn a_request_path_scan_keeps_the_short_deadline() -> Outcome<()> { |
| 217 | let nz = 2usize; |
| 218 | let (api, chans) = res!(harness(nz as u16)); |
| 219 | let stop = Arc::new(AtomicBool::new(false)); |
| 220 | let mut handles = Vec::new(); |
| 221 | for z in 0..nz { |
| 222 | handles.push(res!(busy_scan_bot(&chans, z, stop.clone()))); |
| 223 | } |
| 224 | |
| 225 | let t0 = Instant::now(); |
| 226 | let result = api.scan(&ScanOpts::all(), None); |
| 227 | let took = t0.elapsed(); |
| 228 | |
| 229 | stop.store(true, Ordering::Relaxed); |
| 230 | for handle in handles { |
| 231 | let _ = handle.join(); |
| 232 | } |
| 233 | |
| 234 | let e = match result { |
| 235 | Err(e) => e, |
| 236 | Ok(entries) => return Err(err!( |
| 237 | "A scan served by bots busy for {:?} returned {} entries after {:?}. \ |
| 238 | The request path deadline, constant::USER_REQUEST_TIMEOUT ({:?}), \ |
| 239 | no longer bounds a scan.", |
| 240 | BUSY, entries.len(), took, constant::USER_REQUEST_TIMEOUT; |
| 241 | Test, Invalid)), |
| 242 | }; |
| 243 | if took > USER_DEADLINE_CEILING { |
| 244 | return Err(err!( |
| 245 | "The scan failed, but only after {:?}, beyond the {:?} a call bounded by \ |
| 246 | constant::USER_REQUEST_TIMEOUT ({:?}) may take.", |
| 247 | took, USER_DEADLINE_CEILING, constant::USER_REQUEST_TIMEOUT; |
| 248 | Test, Invalid)); |
| 249 | } |
| 250 | // The failure has to say what it was and what to do about it, since the bare |
| 251 | // shortfall from the responder cost two hours of wrong diagnoses. |
| 252 | let text = fmt!("{:?}", e); |
| 253 | for want in ["scan", "scan_with_wait", "USER_REQUEST_TIMEOUT"] { |
| 254 | if !text.contains(want) { |
| 255 | return Err(err!( |
| 256 | "The scan timeout error does not mention {:?}, so a reader must open \ |
| 257 | api.rs to learn what timed out or what governs it. It says: {}", |
| 258 | want, text; |
| 259 | Test, Missing)); |
| 260 | } |
| 261 | } |
| 262 | Ok(()) |
| 263 | } |
| 264 | |
| 265 | /// A caller that knows it is off the request path names its own deadline, and that |
| 266 | /// deadline, not `USER_REQUEST_WAIT`, is what bounds the walk. |
| 267 | fn a_deliberate_walk_can_ask_for_longer() -> Outcome<()> { |
| 268 | let nz = 2usize; |
| 269 | let (api, chans) = res!(harness(nz as u16)); |
| 270 | let stop = Arc::new(AtomicBool::new(false)); |
| 271 | let mut handles = Vec::new(); |
| 272 | for z in 0..nz { |
| 273 | handles.push(res!(busy_scan_bot(&chans, z, stop.clone()))); |
| 274 | } |
| 275 | |
| 276 | let wait = res!(Wait::new(BUSY + Duration::from_secs(10), constant::CHECK_INTERVAL)); |
| 277 | let t0 = Instant::now(); |
| 278 | let result = api.scan_with_wait(&ScanOpts::all(), None, wait); |
| 279 | let took = t0.elapsed(); |
| 280 | |
| 281 | stop.store(true, Ordering::Relaxed); |
| 282 | for handle in handles { |
| 283 | let _ = handle.join(); |
| 284 | } |
| 285 | |
| 286 | if let Err(e) = result { |
| 287 | return Err(err!(e, |
| 288 | "A scan given a deadline of its own failed after {:?} against bots busy for \ |
| 289 | {:?}, so scan_with_wait is not honouring the wait it was handed.", took, BUSY; |
| 290 | Test)); |
| 291 | } |
| 292 | if took < BUSY { |
| 293 | return Err(err!( |
| 294 | "The scan returned after {:?}, sooner than the {:?} the stand-in scan bots \ |
| 295 | were busy for, so the longer deadline was never tested.", took, BUSY; |
| 296 | Test, Invalid)); |
| 297 | } |
| 298 | Ok(()) |
| 299 | } |