From 61a92920c298e44465c57e45dcd4c1868c311a06 Mon Sep 17 00:00:00 2001 From: Mark Poliakov Date: Thu, 25 Nov 2021 12:02:25 +0200 Subject: [PATCH] feature: trace! levels --- kernel/src/debug.rs | 15 ++++++++++++++- kernel/src/syscall/mod.rs | 10 ++++++---- libsys/src/calls.rs | 4 +++- libsys/src/debug.rs | 10 ++++++++++ libsys/src/lib.rs | 1 + libusr/src/allocator.rs | 6 +++--- libusr/src/env.rs | 4 ++-- libusr/src/lib.rs | 4 ++-- libusr/src/os.rs | 13 ++++++++++--- libusr/src/signal.rs | 3 ++- libusr/src/sys/mod.rs | 1 + user/src/fuzzy/main.rs | 2 +- user/src/shell/main.rs | 9 +++++++-- 13 files changed, 62 insertions(+), 20 deletions(-) create mode 100644 libsys/src/debug.rs diff --git a/kernel/src/debug.rs b/kernel/src/debug.rs index 067eefe..d75bab0 100644 --- a/kernel/src/debug.rs +++ b/kernel/src/debug.rs @@ -12,6 +12,7 @@ //! * [errorln!] use crate::dev::serial::SerialDevice; +use libsys::debug::TraceLevel; use core::fmt; /// Kernel logging levels @@ -27,6 +28,18 @@ pub enum Level { Error, } +impl From for Level { + #[inline(always)] + fn from(l: TraceLevel) -> Self { + match l { + TraceLevel::Debug => Self::Debug, + TraceLevel::Info => Self::Info, + TraceLevel::Warn => Self::Warn, + TraceLevel::Error => Self::Error, + } + } +} + struct SerialOutput { inner: &'static T, } @@ -101,7 +114,7 @@ macro_rules! errorln { } #[doc(hidden)] -pub fn _debug(_level: Level, args: fmt::Arguments) { +pub fn _debug(level: Level, args: fmt::Arguments) { use crate::arch::machine; use fmt::Write; diff --git a/kernel/src/syscall/mod.rs b/kernel/src/syscall/mod.rs index 8cdac5b..762d909 100644 --- a/kernel/src/syscall/mod.rs +++ b/kernel/src/syscall/mod.rs @@ -9,6 +9,7 @@ use core::ops::DerefMut; use core::time::Duration; use libsys::{ abi::SystemCall, + debug::TraceLevel, error::Errno, ioctl::IoctlCmd, proc::{ExitCode, Pid}, @@ -319,10 +320,11 @@ pub fn syscall(num: SystemCall, args: &[usize]) -> Result { // Debugging SystemCall::DebugTrace => { - let buf = arg::str_ref(args[0], args[1])?; - print!(Level::Debug, "[trace] "); - print!(Level::Debug, "{}", buf); - println!(Level::Debug, ""); + let level = TraceLevel::from_repr(args[0]).map(Level::from).ok_or(Errno::InvalidArgument)?; + let buf = arg::str_ref(args[1], args[2])?; + let thread = Thread::current(); + let proc = thread.owner().unwrap(); + println!(level, "[trace {:?}:{}] {}", proc.id(), thread.id(), buf); Ok(args[1]) } diff --git a/libsys/src/calls.rs b/libsys/src/calls.rs index 7405fc1..d78abb6 100644 --- a/libsys/src/calls.rs +++ b/libsys/src/calls.rs @@ -1,6 +1,7 @@ use crate::abi::SystemCall; use crate::{ error::Errno, + debug::TraceLevel, ioctl::IoctlCmd, proc::{ExitCode, Pid}, signal::{Signal, SignalDestination}, @@ -104,10 +105,11 @@ pub fn sys_ex_nanosleep(ns: u64, rem: &mut [u64; 2]) -> Result<(), Errno> { /// /// System call #[inline(always)] -pub fn sys_ex_debug_trace(msg: &[u8]) -> Result<(), Errno> { +pub fn sys_ex_debug_trace(level: TraceLevel, msg: &[u8]) -> Result<(), Errno> { Errno::from_syscall_unit(unsafe { syscall!( SystemCall::DebugTrace, + argn!(level.repr()), argp!(msg.as_ptr()), argn!(msg.len()) ) diff --git a/libsys/src/debug.rs b/libsys/src/debug.rs new file mode 100644 index 0000000..cafc5d9 --- /dev/null +++ b/libsys/src/debug.rs @@ -0,0 +1,10 @@ +use enum_repr::EnumRepr; + +#[EnumRepr(type = "usize")] +#[derive(Clone, Copy, Debug, PartialEq, Eq, PartialOrd, Ord)] +pub enum TraceLevel { + Debug = 1, + Info = 2, + Warn = 3, + Error = 4, +} diff --git a/libsys/src/lib.rs b/libsys/src/lib.rs index 8c4e278..ddafbff 100644 --- a/libsys/src/lib.rs +++ b/libsys/src/lib.rs @@ -5,6 +5,7 @@ extern crate bitflags; pub mod abi; +pub mod debug; pub mod error; pub mod ioctl; pub mod mem; diff --git a/libusr/src/allocator.rs b/libusr/src/allocator.rs index 7976520..c803689 100644 --- a/libusr/src/allocator.rs +++ b/libusr/src/allocator.rs @@ -1,6 +1,6 @@ use core::alloc::{Layout, GlobalAlloc}; use core::sync::atomic::{AtomicUsize, Ordering}; -use libsys::mem::memset; +use libsys::{debug::TraceLevel, mem::memset}; use crate::trace; @@ -16,14 +16,14 @@ unsafe impl GlobalAlloc for Allocator { if res > 65536 { panic!("Out of memory"); } - trace!("alloc({:?}) = {:p}", layout, &ALLOC_DATA[res]); + trace!(TraceLevel::Debug, "alloc({:?}) = {:p}", layout, &ALLOC_DATA[res]); let res = &mut ALLOC_DATA[res] as *mut _; memset(res, 0, layout.size()); res } unsafe fn dealloc(&self, ptr: *mut u8, layout: Layout) { - trace!("free({:p}, {:?})", ptr, layout); + trace!(TraceLevel::Debug, "free({:p}, {:?})", ptr, layout); } } diff --git a/libusr/src/env.rs b/libusr/src/env.rs index 42a0226..ce81bc6 100644 --- a/libusr/src/env.rs +++ b/libusr/src/env.rs @@ -1,4 +1,4 @@ -use libsys::ProgramArgs; +use libsys::{debug::TraceLevel, ProgramArgs}; use alloc::vec::Vec; use crate::trace; @@ -17,5 +17,5 @@ pub(crate) unsafe fn setup_env(arg: &ProgramArgs) { PROGRAM_ARGS.push(string); } - trace!("args = {:?}", PROGRAM_ARGS); + trace!(TraceLevel::Debug, "args = {:?}", PROGRAM_ARGS); } diff --git a/libusr/src/lib.rs b/libusr/src/lib.rs index 4474625..7386805 100644 --- a/libusr/src/lib.rs +++ b/libusr/src/lib.rs @@ -7,7 +7,7 @@ extern crate lazy_static; extern crate alloc; use core::panic::PanicInfo; -use libsys::{ProgramArgs, proc::ExitCode}; +use libsys::{debug::TraceLevel, ProgramArgs, proc::ExitCode}; mod allocator; pub mod env; @@ -40,6 +40,6 @@ fn panic_handler(pi: &PanicInfo) -> ! { // TODO unwind to send panic argument back to parent thread // TODO print to stdout/stderr (if available) let thread = thread::current(); - trace!("{:?} panicked: {:?}", thread, pi); + trace!(TraceLevel::Error, "{:?} panicked: {:?}", thread, pi); sys::sys_exit(ExitCode::from(-1)); } diff --git a/libusr/src/os.rs b/libusr/src/os.rs index f7d0f10..3c9a592 100644 --- a/libusr/src/os.rs +++ b/libusr/src/os.rs @@ -1,9 +1,16 @@ +use libsys::debug::TraceLevel; use crate::sys; use core::fmt; #[macro_export] macro_rules! trace { - ($($args:tt)+) => ($crate::os::_trace(format_args!($($args)+))) + ($level:expr, $($args:tt)+) => ($crate::os::_trace($level, format_args!($($args)+))) +} + + +#[macro_export] +macro_rules! trace_debug { + ($($args:tt)+) => ($crate::os::_trace($crate::sys::debug::TraceLevel::Debug, format_args!($($args)+))) } struct BufferWriter<'a> { @@ -21,7 +28,7 @@ impl fmt::Write for BufferWriter<'_> { } } -pub fn _trace(args: fmt::Arguments) { +pub fn _trace(level: TraceLevel, args: fmt::Arguments) { use core::fmt::Write; static mut BUFFER: [u8; 4096] = [0; 4096]; let mut writer = BufferWriter { @@ -29,5 +36,5 @@ pub fn _trace(args: fmt::Arguments) { pos: 0, }; writer.write_fmt(args).ok(); - sys::sys_ex_debug_trace(unsafe { &BUFFER[..writer.pos] }).ok(); + sys::sys_ex_debug_trace(level, unsafe { &BUFFER[..writer.pos] }).ok(); } diff --git a/libusr/src/signal.rs b/libusr/src/signal.rs index f34793c..8417122 100644 --- a/libusr/src/signal.rs +++ b/libusr/src/signal.rs @@ -1,5 +1,6 @@ use crate::trace; use libsys::{ + debug::TraceLevel, calls::{sys_ex_sigreturn, sys_exit}, proc::ExitCode, signal::Signal, @@ -26,7 +27,7 @@ pub fn set_handler(sig: Signal, handler: SignalHandler) -> SignalHandler { #[inline(never)] pub(crate) extern "C" fn signal_handler(arg: Signal) -> ! { // TODO tpidr_el0 is invalidated when entering signal context - trace!("Entered signal handler: arg={:?}", arg); + trace!(TraceLevel::Debug, "Entered signal handler: arg={:?}", arg); let no = arg as usize; if no >= 32 { panic!("Undefined signal number: {}", no); diff --git a/libusr/src/sys/mod.rs b/libusr/src/sys/mod.rs index e6727f4..06ac158 100644 --- a/libusr/src/sys/mod.rs +++ b/libusr/src/sys/mod.rs @@ -5,6 +5,7 @@ pub use libsys::abi; pub use libsys::calls::*; pub use libsys::stat::{self, AccessMode, FileDescriptor}; pub use libsys::error::Errno; +pub use libsys::debug; use core::sync::atomic::{Ordering, AtomicBool}; diff --git a/user/src/fuzzy/main.rs b/user/src/fuzzy/main.rs index 6b06d79..36a2629 100644 --- a/user/src/fuzzy/main.rs +++ b/user/src/fuzzy/main.rs @@ -110,7 +110,7 @@ fn random_bytes(buf: &mut [u8]) { #[no_mangle] fn main() -> i32 { let seed = libusr::sys::sys_ex_getcputime().unwrap().as_nanos() as u64 / 13; - trace!("Using seed: {:#x}", seed); + println!("Using seed: {:#x}", seed); random_set_seed(seed); let mut buf = [0; 256]; diff --git a/user/src/shell/main.rs b/user/src/shell/main.rs index 9d7f410..5ecfa12 100644 --- a/user/src/shell/main.rs +++ b/user/src/shell/main.rs @@ -10,6 +10,7 @@ use libusr::io::{self, Read}; use libusr::signal::{self, SignalHandler}; use libusr::sys::{ proc::Pid, sys_execve, sys_setpgid, sys_exit, sys_fork, sys_getpgid, sys_waitpid, Errno, ExitCode, + sys_faccessat, AccessMode, FileDescriptor, Signal, }; @@ -31,6 +32,9 @@ fn execute(line: &str) -> Result { let args: Vec<&str> = line.split(' ').collect(); let cmd = args[0]; + let filename = "/bin/".to_owned() + cmd; + sys_faccessat(None, &filename, AccessMode::X_OK, 0)?; + if let Some(pid) = unsafe { sys_fork()? } { let mut status = 0; sys_waitpid(pid, &mut status)?; @@ -40,7 +44,6 @@ fn execute(line: &str) -> Result { } else { let pgid = sys_setpgid(unsafe { Pid::from_raw(0) }, unsafe { Pid::from_raw(0) }).unwrap(); io::tcsetpgrp(FileDescriptor::STDIN, pgid).unwrap(); - let filename = "/bin/".to_owned() + cmd; sys_execve(&filename, &args).unwrap(); sys_exit(ExitCode::from(-1)); } @@ -67,7 +70,9 @@ fn main() -> i32 { continue; } - execute(line).ok(); + if let Err(e) = execute(line) { + eprintln!("{}: {:?}", line.split(' ').next().unwrap(), e); + } }, Err(_) => { println!("Interrupt!");