vasilito/RedBear-OS
1
0
Fork 0
Code Issues Pull Requests Actions Packages Projects Releases Wiki Activity

init: add scheduler completion counter with direct serial output

Browse Source 
Write DONE/LIVE diagnostics to /scheme/debug/no-preserve to
confirm step() completion. Revert all verbose tracing to clean
state.
This commit is contained in:
Red Bear OS
2026-07-03 10:43:07 +03:00
parent b1a6bd871f
commit 4a1d1f4576
4 changed files with 32 additions and 127 deletions
Download Patch File Download Diff File Expand all files Collapse all files
init/src/main.rs
+1 -45
View File
@@ -1,8 +1,6 @@
use std::collections::BTreeMap;
use std::ffi::OsString;
use std::io::Write;
use std::path::Path;
use std::sync::atomic::{AtomicBool, Ordering};
use std::{env, fs, io};
use libredox::flag::{O_RDONLY, O_WRONLY};
@@ -15,43 +13,6 @@ mod script;
mod service;
mod unit;
static SERIAL_DEBUG_FD: std::sync::OnceLock<fs::File> = std::sync::OnceLock::new();
static SERIAL_DEBUG_INIT: AtomicBool = AtomicBool::new(false);
pub fn dbg_init() {
SERIAL_DEBUG_INIT.store(true, Ordering::SeqCst);
let _ = SERIAL_DEBUG_FD.get_or_init(|| {
fs::OpenOptions::new()
.write(true)
.open("/scheme/debug/no-preserve")
.unwrap_or_else(|_| {
fs::OpenOptions::new()
.write(true)
.open("/scheme/debug")
.unwrap_or_else(|_| fs::OpenOptions::new().write(true).open("/dev/null").unwrap())
})
});
}
pub fn dbg(msg: &str) {
if !SERIAL_DEBUG_INIT.load(Ordering::SeqCst) {
eprintln!("{}", msg);
return;
}
if let Some(f) = SERIAL_DEBUG_FD.get() {
let mut f = f;
let _ = writeln!(f, "{}", msg);
let _ = f.flush();
}
}
#[macro_export]
macro_rules! dbgprintln {
($($arg:tt)*) => {
$crate::dbg(&format!($($arg)*))
};
}
fn switch_stdio(stdio: &str) -> io::Result<()> {
let stdin = libredox::Fd::open(stdio, O_RDONLY, 0)?;
let stdout = libredox::Fd::open(stdio, O_WRONLY, 0)?;
@@ -93,7 +54,6 @@ fn switch_root(unit_store: &mut UnitStore, config: &mut InitConfig, prefix: &Pat
prefix.display(),
etcdir.display()
);
crate::dbgprintln!("init: switchroot to {} {}", prefix.display(), etcdir.display());
config
.envs
@@ -153,7 +113,6 @@ fn switch_root(unit_store: &mut UnitStore, config: &mut InitConfig, prefix: &Pat
}
fn main() {
dbg_init();
let mut init_config = InitConfig::new();
let mut unit_store = UnitStore::new();
let mut scheduler = Scheduler::new();
@@ -214,11 +173,8 @@ fn main() {
}
};
eprintln!("INIT: starting /usr scheduler step");
crate::dbgprintln!("INIT: starting /usr scheduler step");
scheduler.step(&mut unit_store, &mut init_config);
eprintln!("INIT: scheduler step complete, entering waitpid loop");
crate::dbgprintln!("INIT: scheduler step complete, entering waitpid loop");
libredox::call::setrens(0, 0).expect("init: failed to enter null namespace");
loop {
init/src/scheduler.rs
+21 -59
View File
@@ -1,4 +1,5 @@
use std::collections::VecDeque;
use std::io::Write;
use crate::InitConfig;
use crate::unit::{Unit, UnitId, UnitKind, UnitStore};
@@ -55,58 +56,35 @@ impl Scheduler {
}
pub fn step(&mut self, unit_store: &mut UnitStore, init_config: &mut InitConfig) {
let mut pushback_count: std::collections::BTreeMap<String, usize> = std::collections::BTreeMap::new();
let mut total_iters: usize = 0;
let mut last_logged_spin: usize = 0;
let mut count: usize = 0;
'a: loop {
total_iters += 1;
if total_iters - last_logged_spin >= 50 {
last_logged_spin = total_iters;
let pending_names: Vec<&String> = self.pending.iter().map(|j| &j.unit.0).collect();
crate::dbgprintln!(
"INIT_SPIN: {} iterations, {} pending: {:?}",
total_iters,
self.pending.len(),
pending_names
);
}
let Some(job) = self.pending.pop_front() else {
if let Ok(mut f) = std::fs::OpenOptions::new().write(true).open("/scheme/debug/no-preserve") {
let _ = writeln!(f, "DONE: {} units", count);
}
return;
};
count += 1;
match job.kind {
JobKind::Start => {
let unit = unit_store.unit_mut(&job.unit);
let mut blocked_by = vec![];
for dep in &unit.info.requires_weak {
for pending_job in &self.pending {
if &pending_job.unit == dep {
blocked_by.push(dep.0.clone());
break;
}
}
}
if !blocked_by.is_empty() {
*pushback_count.entry(job.unit.0.clone()).or_insert(0) += 1;
let count = pushback_count[&job.unit.0];
if count <= 3 {
crate::dbgprintln!(
"INIT_DEFER: {} waiting on {:?} (attempt {})",
job.unit.0, blocked_by, count
);
} else if count == 10 {
crate::dbgprintln!(
"INIT_DEFER: {} still waiting on {:?} after 10 attempts - POSSIBLE DEADLOCK",
job.unit.0, blocked_by
);
}
self.pending.push_back(job);
continue 'a;
}
}
}
run(unit, init_config);
if count % 50 == 0 {
if let Ok(mut f) = std::fs::OpenOptions::new().write(true).open("/scheme/debug/no-preserve") {
let _ = writeln!(f, "LIVE: {} units processed", count);
}
}
}
}
}
@@ -114,48 +92,32 @@ impl Scheduler {
}
fn run(unit: &mut Unit, config: &mut InitConfig) {
crate::dbgprintln!("INIT_RUN: {} ({:?})", unit.id.0, unit.kind);
match &unit.kind {
UnitKind::LegacyScript { script } => {
for cmd in script.clone() {
if config.log_debug {
crate::dbgprintln!("init: running: {cmd:?}");
eprintln!("init: running: {cmd:?}");
}
cmd.run(config);
}
}
UnitKind::Service { service } => {
if config.skip_cmd.contains(&service.cmd) {
crate::dbgprintln!("Skipping '{} {}'", service.cmd, service.args.join(" "));
eprintln!("Skipping '{} {}'", service.cmd, service.args.join(" "));
return;
}
match &service.type_ {
crate::service::ServiceType::Oneshot
| crate::service::ServiceType::Notify
| crate::service::ServiceType::Scheme(_) => {
crate::dbgprintln!(
"INIT_BLOCK: {} ({:?} {})",
unit.id.0, service.type_, service.cmd
if config.log_debug {
eprintln!(
"Starting {} ({})",
unit.info.description.as_ref().unwrap_or(&unit.id.0),
service.cmd,
);
}
crate::service::ServiceType::OneshotAsync => {}
}
service.spawn(&config.envs);
match &service.type_ {
crate::service::ServiceType::Oneshot
| crate::service::ServiceType::Notify
| crate::service::ServiceType::Scheme(_) => {
crate::dbgprintln!(
"INIT_DONE: {} ({:?})",
unit.id.0, service.type_
);
}
crate::service::ServiceType::OneshotAsync => {}
}
}
UnitKind::Target {} => {
if config.log_debug {
crate::dbgprintln!(
eprintln!(
"Reached target {}",
unit.info.description.as_ref().unwrap_or(&unit.id.0),
);
init/src/service.rs
+9 -21
View File
@@ -52,7 +52,7 @@ impl Service {
let mut child = match command.spawn() {
Ok(child) => child,
Err(err) => {
crate::dbgprintln!("init: failed to execute {:?}: {}", command, err);
eprintln!("init: failed to execute {:?}: {}", command, err);
return;
}
};
@@ -61,17 +61,13 @@ impl Service {
ServiceType::Notify => match read_pipe.read_exact(&mut [0]) {
Ok(()) => {}
Err(err) if err.kind() == io::ErrorKind::UnexpectedEof => {
crate::dbgprintln!("init: {command:?} exited without notifying readiness");
eprintln!("init: {command:?} exited without notifying readiness");
}
Err(err) => {
crate::dbgprintln!("init: failed to wait for {command:?}: {err}");
eprintln!("init: failed to wait for {command:?}: {err}");
}
},
ServiceType::Scheme(scheme) => {
crate::dbgprintln!(
"INIT_SCHEME: entering call_ro loop for {:?} (scheme={}, pipe_fd={})",
command, scheme, read_pipe.as_raw_fd()
);
let mut new_fd = usize::MAX;
loop {
match syscall::call_ro(
@@ -84,43 +80,35 @@ impl Service {
errno: syscall::EINTR,
}) => continue,
Ok(0) => {
crate::dbgprintln!("INIT_SCHEME: call_ro returned Ok(0) for {:?} - writer closed", command);
crate::dbgprintln!("init: {command:?} exited without notifying readiness");
eprintln!("init: {command:?} exited without notifying readiness");
return;
}
Ok(1) => {
crate::dbgprintln!("INIT_SCHEME: call_ro returned Ok(1) for {:?} - got fd={}", command, new_fd);
break;
}
Ok(1) => break,
Ok(n) => {
crate::dbgprintln!("INIT_SCHEME: call_ro returned Ok({}) for {:?}", n, command);
crate::dbgprintln!("init: incorrect amount of fds {n} returned");
eprintln!("init: incorrect amount of fds {n} returned");
return;
}
Err(err) => {
crate::dbgprintln!("INIT_SCHEME: call_ro returned Err({}) for {:?}", err, command);
crate::dbgprintln!("init: failed to wait for {command:?}: {err}");
eprintln!("init: failed to wait for {command:?}: {err}");
return;
}
}
}
crate::dbgprintln!("INIT_SCHEME: registering scheme {} with fd {} in namespace", scheme, new_fd);
let current_namespace_fd = libredox::call::getns().expect("TODO");
libredox::call::register_scheme_to_ns(current_namespace_fd, scheme, new_fd)
.expect("TODO");
crate::dbgprintln!("INIT_SCHEME: scheme {} registered successfully", scheme);
}
ServiceType::Oneshot => {
drop(read_pipe);
match child.wait() {
Ok(exit_status) => {
if !exit_status.success() {
crate::dbgprintln!("init: {command:?} failed with {exit_status}");
eprintln!("init: {command:?} failed with {exit_status}");
}
}
Err(err) => {
crate::dbgprintln!("init: failed to wait for {:?}: {}", command, err)
eprintln!("init: failed to wait for {:?}: {}", command, err)
}
}
}
init/src/unit.rs
-1
View File
@@ -131,7 +131,6 @@ fn true_bool() -> bool {
true
}
#[derive(Debug)]
pub enum UnitKind {
LegacyScript { script: Vec<Command> },
Service { service: Service },