oxedyne/fe2o3/fe2o3_o3db_sync/tests/idle_cpu.rs
3.9 KiB, 11 runs
created by r1870400018:13512, 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 test for the idle busy-poll in the Ozone server bot. |
| 2 | //! |
| 3 | //! The `ServerBot` used to wait on its internal channel with a one |
| 4 | //! microsecond `recv_timeout`, so an idle database woke roughly a |
| 5 | //! million times a second per server bot and burned around a fifth of |
| 6 | //! a CPU core doing nothing. The fix makes the bot block on `recv` |
| 7 | //! instead. This test starts a database, lets it fall completely |
| 8 | //! idle, and asserts that the whole process consumes only a trivial |
| 9 | //! amount of CPU time over the measurement window. |
| 10 | //! |
| 11 | //! [Written with AI entirely](https://need2know.ai/entirely-ai/code)\ |
| 12 | //! Anthropic Claude |
| 13 | |
| 14 | use oxedyne_fe2o3_core::{ |
| 15 | prelude::*, |
| 16 | alt::Override, |
| 17 | rand::Rand, |
| 18 | }; |
| 19 | use oxedyne_fe2o3_crypto::enc::EncryptionScheme; |
| 20 | use oxedyne_fe2o3_hash::{ |
| 21 | csum::ChecksumScheme, |
| 22 | hash::HashScheme, |
| 23 | }; |
| 24 | use oxedyne_fe2o3_iop_db::api::RestSchemesOverride; |
| 25 | use oxedyne_fe2o3_o3db_sync::{ |
| 26 | data::core::RestSchemesInput, |
| 27 | test::setup, |
| 28 | }; |
| 29 | use oxedyne_fe2o3_sys::proc_self::ProcSelf; |
| 30 | |
| 31 | use std::{ |
| 32 | path::Path, |
| 33 | thread, |
| 34 | time::Duration, |
| 35 | }; |
| 36 | |
| 37 | #[test] |
| 38 | fn main() -> Outcome<()> { |
| 39 | log_set_level!("warn"); |
| 40 | let outcome = run(); |
| 41 | log_finish_wait!(); |
| 42 | outcome |
| 43 | } |
| 44 | |
| 45 | fn run() -> Outcome<()> { |
| 46 | |
| 47 | // Kernel clock tick rate assumed by /proc accounting on Linux. |
| 48 | // One tick is therefore 10 ms of CPU time. |
| 49 | const TICKS_PER_SEC: u64 = 100; |
| 50 | // Length of the idle observation window. |
| 51 | const IDLE_SECS: u64 = 4; |
| 52 | // Ceiling on the fraction of a single core the idle database may |
| 53 | // consume. The old one microsecond poll burned tens of percent of |
| 54 | // a core; blocking receives sit far below one percent. Five |
| 55 | // percent leaves generous headroom for incidental wake-ups (async |
| 56 | // logging, the one second zone state updates) while still failing |
| 57 | // hard if the microsecond spin ever returns. |
| 58 | const MAX_CORE_FRACTION: f64 = 0.05; |
| 59 | |
| 60 | let db_dir = Path::new("./test_db_idle_cpu"); |
| 61 | res!(std::fs::create_dir_all(db_dir)); |
| 62 | let db_root = res!(db_dir.canonicalize()); |
| 63 | |
| 64 | let mut enckey = [0u8; 32]; |
| 65 | Rand::fill_u8(&mut enckey); |
| 66 | let aes_gcm = res!(EncryptionScheme::new_aes_256_gcm_with_key(&enckey[..])); |
| 67 | let crc32 = ChecksumScheme::new_crc32(); |
| 68 | let _schms2: RestSchemesOverride<EncryptionScheme, HashScheme> = |
| 69 | RestSchemesOverride::default().set_encrypter(Override::Default(aes_gcm.clone())); |
| 70 | let schms_input = RestSchemesInput::new( |
| 71 | Some(aes_gcm.clone()), |
| 72 | None::<HashScheme>, |
| 73 | None::<HashScheme>, |
| 74 | Some(crc32.clone()), |
| 75 | ); |
| 76 | |
| 77 | let mut cfg = res!(setup::default_cfg()); |
| 78 | // Every zone in this test's own directory, not the shared container the default names. |
| 79 | cfg.zone_overrides = Default::default(); |
| 80 | |
| 81 | let db = res!(setup::start_db( |
| 82 | db_root.clone(), |
| 83 | Some(cfg), |
| 84 | schms_input, |
| 85 | None, |
| 86 | false, |
| 87 | true, |
| 88 | )); |
| 89 | |
| 90 | // Let start-up churn settle before measuring. |
| 91 | thread::sleep(Duration::from_secs(1)); |
| 92 | |
| 93 | let ticks_before = res!(ProcSelf::cpu_ticks()); |
| 94 | thread::sleep(Duration::from_secs(IDLE_SECS)); |
| 95 | let ticks_after = res!(ProcSelf::cpu_ticks()); |
| 96 | |
| 97 | res!(db.shutdown()); |
| 98 | |
| 99 | let ticks_used = ticks_after.saturating_sub(ticks_before); |
| 100 | // CPU seconds consumed during the idle window. |
| 101 | let cpu_secs = ticks_used as f64 / TICKS_PER_SEC as f64; |
| 102 | // Fraction of one core: idle CPU seconds over wall-clock seconds. |
| 103 | let core_fraction = cpu_secs / IDLE_SECS as f64; |
| 104 | |
| 105 | test!(sync_log::stream(), |
| 106 | "Idle database consumed {} CPU ticks ({:.3} s) over {} s: {:.2}% of one core.", |
| 107 | ticks_used, cpu_secs, IDLE_SECS, core_fraction * 100.0); |
| 108 | |
| 109 | if core_fraction > MAX_CORE_FRACTION { |
| 110 | return Err(err!( |
| 111 | "Idle database burned {:.2}% of a core, exceeding the {:.2}% ceiling; \ |
| 112 | the server bot is likely busy-polling again.", |
| 113 | core_fraction * 100.0, MAX_CORE_FRACTION * 100.0; |
| 114 | Test, Excessive)); |
| 115 | } |
| 116 | |
| 117 | Ok(()) |
| 118 | } |