Skip to content

Commit 01a2a89

Browse files
lasiotuslasiotus
committed
Forward kernel logs to sys-tty.
This fixes [issue 37](#37). PR rust-lang/rust#154837 must go in in order for panics to also behave nicely.
1 parent de56b6e commit 01a2a89

11 files changed

Lines changed: 230 additions & 25 deletions

File tree

‎src/sys/kernel/src/uspace/process.rs‎

Lines changed: 7 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -1829,15 +1829,19 @@ impl Thread {
18291829
.drop_stacks(&self.user_stack, &self.kernel_stack_segment);
18301830
}
18311831

1832+
#[cfg(debug_assertions)]
18321833
fn print_backtrace(&self) {
18331834
let backtrace = self
18341835
.owner()
18351836
.address_space
18361837
.get_backtrace(self.tcb.rip(), self.tcb.rbp());
1837-
crate::raw_log!("\n{}: backtrace:", self.debug_name());
1838+
1839+
let mut log_msg = alloc::format!("\nKILLED: {}: backtrace:\n", self.debug_name());
18381840
for val in backtrace {
1839-
crate::raw_log!("\t0x{:x} \\", val);
1841+
log_msg.push_str(alloc::format!("\t0x{val:x} \\\n").as_str());
18401842
}
1843+
1844+
log::debug!("{log_msg}");
18411845
}
18421846

18431847
fn on_pagefault(&self) {
@@ -1980,6 +1984,7 @@ impl Thread {
19801984
}
19811985
ThreadOffCpuReason::KilledGpf => {
19821986
{
1987+
#[cfg(debug_assertions)]
19831988
self.print_backtrace();
19841989
let mut status = self.status.lock(line!());
19851990
log::debug!("Thread killed (#GPF): {:?}", *status);

‎src/sys/kernel/src/uspace/serial_console.rs‎

Lines changed: 141 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -1,26 +1,50 @@
1+
//! Support for the userspace serial console "driver" (sys-tty).
2+
//!
3+
//! At the moment, once the "driver" is set, it cannot be changed.
4+
//! An important part of this logic is to forward kernel logs to
5+
//! the userspace driver to avoid kernel logs intermixing with userspace
6+
//! output.
7+
use crate::util::StaticRef;
8+
19
use super::sysobject::SysObject;
2-
use alloc::{borrow::ToOwned, sync::Arc};
10+
use alloc::{borrow::ToOwned, boxed::Box, sync::Arc};
311
use core::sync::atomic::*;
4-
use moto_sys::ErrorCode;
12+
use moto_sys::{ErrorCode, SysRay};
513

614
struct SerialConsole {
715
owner_pid: AtomicU64,
816
this_object: Arc<SysObject>,
17+
18+
uspace_log_buf_addr: AtomicUsize,
19+
uspace_log_buf_offset_addr: AtomicUsize,
20+
uspace_log_buf_offset: crate::util::SpinLock<usize>,
21+
22+
console_driver_address_space:
23+
crate::util::SpinLock<Option<Arc<crate::mm::user::UserAddressSpace>>>,
924
}
1025

1126
static CONSOLE: crate::util::StaticRef<SerialConsole> = crate::util::StaticRef::default_const();
1227

13-
pub fn init() {
14-
use alloc::boxed::Box;
28+
// We don't (want to) support nested logging, so we protect top-level log
29+
// routines with per cpu bool flags, and log directly to serial port when nested.
30+
static PERCPU_LOG_GUARD: StaticRef<crate::util::StaticPerCpu<bool>> = StaticRef::default_const();
1531

32+
pub fn init() {
1633
CONSOLE.set(Box::leak(Box::new(SerialConsole {
1734
owner_pid: AtomicU64::new(super::process::KERNEL_PID.as_u64()),
1835
this_object: SysObject::new(Arc::new("serial_console".to_owned())),
36+
37+
uspace_log_buf_addr: AtomicUsize::new(0),
38+
uspace_log_buf_offset_addr: AtomicUsize::new(0),
39+
uspace_log_buf_offset: crate::util::SpinLock::new(0),
40+
41+
console_driver_address_space: crate::util::SpinLock::new(None),
1942
})));
2043
}
2144

2245
pub(super) fn get_for_process(
2346
process: &super::process::Process,
47+
addresses: &str,
2448
) -> Result<Arc<SysObject>, ErrorCode> {
2549
if CONSOLE.owner_pid.load(Ordering::Acquire) != super::process::KERNEL_PID.as_u64() {
2650
// We do not support transferring console ownership for now.
@@ -32,9 +56,35 @@ pub(super) fn get_for_process(
3256
return Err(moto_rt::E_NOT_ALLOWED);
3357
}
3458

59+
let Some((buf_addr, offset_addr)) = addresses.split_once(':') else {
60+
log::error!("Failed to parse serial console handler parameters");
61+
return Err(moto_rt::E_INVALID_ARGUMENT);
62+
};
63+
64+
let Ok(buf_addr) = buf_addr.parse::<usize>() else {
65+
log::error!("Failed to parse serial console handler parameters");
66+
return Err(moto_rt::E_INVALID_ARGUMENT);
67+
};
68+
69+
let Ok(offset_addr) = offset_addr.parse::<usize>() else {
70+
log::error!("Failed to parse serial console handler parameters");
71+
return Err(moto_rt::E_INVALID_ARGUMENT);
72+
};
73+
74+
PERCPU_LOG_GUARD.set(Box::leak(Box::new(crate::util::StaticPerCpu::init())));
75+
76+
*CONSOLE.console_driver_address_space.lock(line!()) = Some(process.address_space().clone());
77+
78+
CONSOLE
79+
.uspace_log_buf_addr
80+
.store(buf_addr, Ordering::Relaxed);
3581
CONSOLE
3682
.owner_pid
3783
.store(process.pid().as_u64(), Ordering::Relaxed);
84+
CONSOLE
85+
.uspace_log_buf_offset_addr
86+
.store(offset_addr, Ordering::Release);
87+
3888
Ok(CONSOLE.this_object.clone())
3989
}
4090

@@ -45,3 +95,90 @@ pub fn on_irq() {
4595
}
4696
SysObject::wake_irq(&CONSOLE.this_object);
4797
}
98+
99+
pub fn logging_to_uspace() -> bool {
100+
CONSOLE.uspace_log_buf_offset_addr.load(Ordering::Relaxed) != 0
101+
}
102+
103+
pub fn log_to_uspace(msg: &str) -> bool {
104+
assert!(msg.len() < SysRay::CONSOLE_SHARED_BUF_SZ);
105+
106+
let uspace_log_buf_offset_addr = CONSOLE.uspace_log_buf_offset_addr.load(Ordering::Relaxed);
107+
if uspace_log_buf_offset_addr == 0 {
108+
return false;
109+
}
110+
111+
let uspace_log_buf_addr = CONSOLE.uspace_log_buf_addr.load(Ordering::Relaxed);
112+
if uspace_log_buf_addr == 0 {
113+
return false; // Raced with console setup?
114+
}
115+
116+
let bytes = msg.as_bytes();
117+
118+
if PERCPU_LOG_GUARD.is_null() {
119+
PERCPU_LOG_GUARD.set_per_cpu(Box::leak(Box::new(false)));
120+
}
121+
*PERCPU_LOG_GUARD.get_per_cpu() = true;
122+
123+
let mut offset = CONSOLE.uspace_log_buf_offset.lock(line!());
124+
let start = (*offset) & (SysRay::CONSOLE_SHARED_BUF_SZ - 1);
125+
let end = start + bytes.len();
126+
127+
let address_space_guard = CONSOLE.console_driver_address_space.lock(line!());
128+
let address_space = address_space_guard.as_ref().unwrap();
129+
130+
if end <= SysRay::CONSOLE_SHARED_BUF_SZ {
131+
if let Err(err) = address_space.copy_to_user(bytes, (uspace_log_buf_addr + start) as u64) {
132+
log::error!("Failed to log to userspace: {err:?}.");
133+
*PERCPU_LOG_GUARD.get_per_cpu() = false;
134+
return false;
135+
}
136+
} else {
137+
if let Err(err) = address_space.copy_to_user(
138+
&bytes[..(SysRay::CONSOLE_SHARED_BUF_SZ - start)],
139+
(uspace_log_buf_addr + start) as u64,
140+
) {
141+
log::error!("Failed to log to userspace: {err:?}.");
142+
*PERCPU_LOG_GUARD.get_per_cpu() = false;
143+
return false;
144+
}
145+
146+
if let Err(err) = address_space.copy_to_user(
147+
&bytes[(SysRay::CONSOLE_SHARED_BUF_SZ - start)..],
148+
uspace_log_buf_addr as u64,
149+
) {
150+
log::error!("Failed to log to userspace: {err:?}.");
151+
*PERCPU_LOG_GUARD.get_per_cpu() = false;
152+
return false;
153+
}
154+
}
155+
156+
*offset += bytes.len();
157+
let offset_bytes = offset.to_ne_bytes();
158+
159+
if let Err(err) = address_space.copy_to_user(&offset_bytes, uspace_log_buf_offset_addr as u64) {
160+
log::error!("Failed to log to userspace: {err:?}.");
161+
}
162+
163+
core::mem::drop(address_space_guard);
164+
core::mem::drop(offset);
165+
166+
SysObject::wake_irq(&CONSOLE.this_object);
167+
*PERCPU_LOG_GUARD.get_per_cpu() = false;
168+
169+
true
170+
}
171+
172+
pub fn log_to_uspace_protected(msg: &str) -> bool {
173+
if CONSOLE.uspace_log_buf_offset_addr.load(Ordering::Relaxed) == 0 {
174+
return false;
175+
}
176+
if PERCPU_LOG_GUARD.is_null() {
177+
return false;
178+
}
179+
if *PERCPU_LOG_GUARD.get_per_cpu() {
180+
return false;
181+
}
182+
183+
log_to_uspace(msg)
184+
}

‎src/sys/kernel/src/uspace/sys_obj.rs‎

Lines changed: 10 additions & 10 deletions
Original file line numberDiff line numberDiff line change
@@ -198,16 +198,6 @@ fn sys_handle_get(
198198
Err(moto_rt::E_INVALID_ARGUMENT)
199199
}
200200
}
201-
"serial_console" => {
202-
if parent != SysHandle::KERNEL {
203-
return Err(moto_rt::E_INVALID_ARGUMENT);
204-
}
205-
let res = super::serial_console::get_for_process(&thread.owner())?;
206-
207-
#[cfg(debug_assertions)]
208-
log::trace!("Delegated serial console to {}", thread.debug_name());
209-
Ok(thread.owner().add_object(res))
210-
}
211201
_ => {
212202
if let Some((prefix, suffix)) = url.split_once(':') {
213203
match prefix {
@@ -230,6 +220,16 @@ fn sys_handle_get(
230220
"shared" => {
231221
return sys_handle_shared(SysObj::OP_GET, thread, parent, suffix);
232222
}
223+
"serial_console" => {
224+
if parent != SysHandle::KERNEL {
225+
return Err(moto_rt::E_INVALID_ARGUMENT);
226+
}
227+
let res = super::serial_console::get_for_process(&thread.owner(), suffix)?;
228+
229+
#[cfg(debug_assertions)]
230+
log::trace!("Delegated serial console to {}", thread.debug_name());
231+
return Ok(thread.owner().add_object(res));
232+
}
233233
_ => {}
234234
}
235235
}

‎src/sys/kernel/src/uspace/sys_ray.rs‎

Lines changed: 3 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -117,7 +117,9 @@ fn sys_log(
117117
use core::str;
118118
match str::from_utf8(bytes.as_slice()) {
119119
Ok(str) => {
120-
crate::xray::logger::log_user(curr_thread, str);
120+
if !super::serial_console::log_to_uspace(str) {
121+
crate::xray::logger::log_user(curr_thread, str);
122+
}
121123
}
122124
Err(_) => return ResultBuilder::result(moto_rt::E_INVALID_ARGUMENT),
123125
};

‎src/sys/kernel/src/xray/logger.rs‎

Lines changed: 18 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -26,6 +26,24 @@ impl log::Log for Logger {
2626

2727
let cpu = crate::arch::current_cpu();
2828

29+
if crate::uspace::serial_console::logging_to_uspace() {
30+
let msg = alloc::format!(
31+
"{:3}:{:03} {:2}: {:6} {}:{} - {}\n\r",
32+
secs,
33+
millis,
34+
cpu,
35+
record.level(),
36+
target,
37+
line,
38+
record.args()
39+
);
40+
41+
// log_to_uspace() may return false if logging is nested.
42+
if crate::uspace::serial_console::log_to_uspace_protected(msg.as_str()) {
43+
return;
44+
}
45+
}
46+
2947
crate::arch::arch_write_serial!(
3048
"{:3}:{:03} {:2}: {:6} {}:{} - {}\n\r",
3149
secs,

‎src/sys/lib/moto-sys/src/sys_ray.rs‎

Lines changed: 3 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -37,6 +37,9 @@ impl SysRay {
3737
/// Detach the debugger. Note that just putting the handle is not enough.
3838
pub const F_DBG_DETACH: u32 = 8;
3939

40+
/// Used internally by the kernel and sys-tty.
41+
pub const CONSOLE_SHARED_BUF_SZ: usize = 4096; // * 16
42+
4043
#[cfg(feature = "userspace")]
4144
pub fn process_status(handle: SysHandle) -> Result<Option<u64>, ErrorCode> {
4245
let result = do_syscall(

‎src/sys/lib/rt.vdso/src/util/logging.rs‎

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -11,7 +11,7 @@ impl log::Log for MotoLogger {
1111
fn log(&self, record: &Record) {
1212
if self.enabled(record.metadata()) {
1313
crate::moto_log!(
14-
"{} {}:{}: {}",
14+
"{} {}:{}: {}\n",
1515
record.level(),
1616
record.file().unwrap_or("-"),
1717
record.line().unwrap_or(0),

‎src/sys/sys-io/src/logger.rs‎

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -11,7 +11,7 @@ impl log::Log for MotoLogger {
1111
fn log(&self, record: &Record) {
1212
if self.enabled(record.metadata()) {
1313
crate::moto_log!(
14-
"{} {}:{}: {}",
14+
"{} {}:{}: {}\n",
1515
record.level(),
1616
record.file().unwrap_or("-"),
1717
record.line().unwrap_or(0),

‎src/sys/sys-tty/Cargo.toml‎

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -3,7 +3,7 @@ name = "sys-tty"
33
authors = ["The Motor OS Project Developers"]
44
license = "MIT OR Apache-2.0"
55
version = "0.1.0"
6-
edition = "2021"
6+
edition = "2024"
77

88
[dependencies]
99
moto-ipc = { path = "../lib/moto-ipc" }

0 commit comments

Comments
 (0)