diff --git a/Cargo.toml b/Cargo.toml index a27d98d..5bca183 100644 --- a/Cargo.toml +++ b/Cargo.toml @@ -25,6 +25,7 @@ linked_list_allocator = "0.5.0" redox_syscall = "0.1.37" xmas-elf = "0.6" arrayvec = { version = "0.4.7", default-features = false } +log = "0.4" simple-filesystem = { path = "../simple-filesystem" } [build-dependencies] diff --git a/src/arch/x86_64/driver/acpi/mod.rs b/src/arch/x86_64/driver/acpi/mod.rs index d8752af..0e4a755 100644 --- a/src/arch/x86_64/driver/acpi/mod.rs +++ b/src/arch/x86_64/driver/acpi/mod.rs @@ -9,7 +9,7 @@ pub fn init() -> Result { if rsdp.rsdt_physical_address > PHYSICAL_MEMORY_LIMIT { return Err(AcpiError::NotMapped); } - debug!("RSDT at {:#x}", rsdp.rsdt_physical_address); + trace!("RSDT at {:#x}", rsdp.rsdt_physical_address); let rsdt = unsafe{ &*(rsdp.rsdt_physical_address as *const Rsdt) }; let mut madt: Option<&'static Madt> = None; for i in 0 .. rsdt.entry_count() { @@ -18,12 +18,12 @@ pub fn init() -> Result { return Err(AcpiError::NotMapped); } let header = unsafe{ &*(entry as *const Header) }; - // debug!("{:?}", header); + trace!("{:?}", header); if &header.signature == b"APIC" { madt = Some(unsafe{ &*(entry as *const Madt) }); } } - debug!("{:?}", madt); + trace!("{:?}", madt); config_smp(madt.expect("acpi: madt not found.")) } @@ -53,7 +53,7 @@ fn config_smp(madt: &'static Madt) -> Result { let mut cpu_acpi_ids: [u8; MAX_CPU_NUM] = [0; MAX_CPU_NUM]; let mut ioapic_id: Option = None; for entry in madt.entry_iter() { - debug!("{:?}", entry); + trace!("{:?}", entry); match &entry { &MadtEntry::LocalApic(ref lapic) => { cpu_acpi_ids[cpu_num as usize] = lapic.id; @@ -77,7 +77,7 @@ fn config_smp(madt: &'static Madt) -> Result { fn find_rsdp() -> Option<&'static Rsdp> { use util::{Checkable, find_in_memory}; let ebda = unsafe { *(0x40E as *const u16) as usize } << 4; - debug!("EBDA at {:#x}", ebda); + trace!("EBDA at {:#x}", ebda); macro_rules! return_if_find_in { ($begin:expr, $end:expr) => ( diff --git a/src/arch/x86_64/driver/apic/ioapic.rs b/src/arch/x86_64/driver/apic/ioapic.rs index 1f67bcb..9d0adc9 100644 --- a/src/arch/x86_64/driver/apic/ioapic.rs +++ b/src/arch/x86_64/driver/apic/ioapic.rs @@ -19,7 +19,7 @@ pub fn init(ioapic_id: u8) for i in 0.. ioapic.maxintr() + 1 { ioapic.write_irq(i, RedirectionEntry::DISABLED, 0); } - debug!("ioapic: init end"); + info!("ioapic: init end"); } const IOAPIC_ADDRESS : u32 = 0xFEC00000; // Default physical address of IO APIC @@ -81,7 +81,7 @@ impl IoApic { } pub fn enable(&mut self, irq: u8, cpunum: u8) { - debug!("ioapic: enable irq {} @ cpu{}", irq, cpunum); + info!("ioapic: enable irq {} @ cpu{}", irq, cpunum); // Mark interrupt edge-triggered, active high, // enabled, and routed to the given cpunum, // which happens to be that cpu's APIC ID. diff --git a/src/arch/x86_64/driver/apic/lapic.rs b/src/arch/x86_64/driver/apic/lapic.rs index 83aa7e6..3692bf6 100644 --- a/src/arch/x86_64/driver/apic/lapic.rs +++ b/src/arch/x86_64/driver/apic/lapic.rs @@ -13,11 +13,11 @@ pub fn set_addr(lapic_addr: *const ()) { } pub fn init() { - debug!("WARNING: lapic::init use C lib"); + warn!("lapic::init use C lib"); unsafe { lapicinit(); } - debug!("lapic: init end"); + info!("lapic: init end"); } pub fn ack(_irq: u8) { @@ -27,7 +27,7 @@ pub fn ack(_irq: u8) { } pub fn start_ap(apicid: u8, addr: u32) { - debug!("WARNING: lapic::start_ap use C lib"); + warn!("lapic::start_ap use C lib"); unsafe { lapicstartap(apicid, addr); } diff --git a/src/arch/x86_64/driver/mod.rs b/src/arch/x86_64/driver/mod.rs index 1531952..decb194 100644 --- a/src/arch/x86_64/driver/mod.rs +++ b/src/arch/x86_64/driver/mod.rs @@ -19,7 +19,7 @@ pub fn init(mut page_map: impl FnMut(usize)) -> acpi::AcpiResult { let acpi = acpi::init().expect("Failed to init ACPI"); assert_eq!(acpi.lapic_addr as usize, 0xfee00000); - debug!("{:?}", acpi); + trace!("acpi = {:?}", acpi); if cfg!(feature = "use_apic") { pic::disable(); diff --git a/src/arch/x86_64/driver/pic.rs b/src/arch/x86_64/driver/pic.rs index 33a1187..3ef42c1 100644 --- a/src/arch/x86_64/driver/pic.rs +++ b/src/arch/x86_64/driver/pic.rs @@ -10,7 +10,7 @@ pub fn disable() { // Mask all interrupts (Copy from xv6 x86_64) MASTER.lock().cmd.write(0xFF); SLAVE.lock().cmd.write(0xFF); - debug!("pic: disabled"); + info!("pic: disabled"); } pub fn init() { @@ -43,7 +43,7 @@ pub fn init() { master.ack(); slave.ack(); - debug!("pic: init end"); + info!("pic: init end"); } pub fn enable_irq(irq: u8) diff --git a/src/arch/x86_64/driver/pit.rs b/src/arch/x86_64/driver/pit.rs index 87d1b7f..01c91a0 100644 --- a/src/arch/x86_64/driver/pit.rs +++ b/src/arch/x86_64/driver/pit.rs @@ -5,7 +5,7 @@ static mut PIT: Pit = Pit::new(0x40); pub fn init() { assert_has_not_been_called!("pit::init must be called only once"); unsafe{ PIT.init(100); } - debug!("pit: init end"); + info!("pit: init end"); } struct Pit { diff --git a/src/arch/x86_64/driver/vga.rs b/src/arch/x86_64/driver/vga.rs index 197307e..09ab3d2 100644 --- a/src/arch/x86_64/driver/vga.rs +++ b/src/arch/x86_64/driver/vga.rs @@ -8,7 +8,7 @@ pub const VGA_BUFFER: Unique = unsafe{ }; #[allow(dead_code)] -#[derive(Debug, Clone, Copy)] +#[derive(Debug, Clone, Copy, Eq, PartialEq)] #[repr(u8)] pub enum Color { Black = 0, diff --git a/src/arch/x86_64/gdt.rs b/src/arch/x86_64/gdt.rs index 76292f3..b93f969 100644 --- a/src/arch/x86_64/gdt.rs +++ b/src/arch/x86_64/gdt.rs @@ -58,10 +58,10 @@ static mut TSS_PTR: Unique = unsafe{ Unique::new_unchecked(0 a /// /// 每次进入用户态前，都要调用此函数，才能保证正确返回内核态 pub fn set_ring0_rsp(rsp: usize) { -// debug!("gdt.set_ring0_rsp: {:#x}", rsp); + trace!("gdt.set_ring0_rsp: {:#x}", rsp); unsafe { TSS_PTR.as_mut().privilege_stack_table[0] = VirtualAddress(rsp); -// debug!("TSS:\n{:?}", TSS_PTR.as_ref()); + trace!("TSS:\n{:?}", TSS_PTR.as_ref()); } } diff --git a/src/arch/x86_64/interrupt/handler.rs b/src/arch/x86_64/interrupt/handler.rs index 55fce27..ac2c8b7 100644 --- a/src/arch/x86_64/interrupt/handler.rs +++ b/src/arch/x86_64/interrupt/handler.rs @@ -5,12 +5,12 @@ use self::template::*; pub type TrapFrame = InterruptStackP; interrupt_stack!(breakpoint, stack, { - println!("\nEXCEPTION: Breakpoint"); + error!("\nEXCEPTION: Breakpoint"); stack.dump(); }); interrupt_error_p!(double_fault, stack, { - println!("\nEXCEPTION: Double Fault"); + error!("\nEXCEPTION: Double Fault"); stack.dump(); loop {} }); @@ -18,7 +18,7 @@ interrupt_error_p!(double_fault, stack, { interrupt_error_p!(page_fault, stack, { use x86_64::registers::control_regs::cr2; let addr = cr2().0; - println!("\nEXCEPTION: Page Fault @ {:#x}, code: {:#x}", addr, stack.code); + error!("\nEXCEPTION: Page Fault @ {:#x}, code: {:#x}", addr, stack.code); use memory::page_fault_handler; if page_fault_handler(addr) { @@ -30,13 +30,13 @@ interrupt_error_p!(page_fault, stack, { }); interrupt_error_p!(general_protection_fault, stack, { - println!("\nEXCEPTION: General Protection Fault"); + error!("\nEXCEPTION: General Protection Fault"); stack.dump(); loop {} }); interrupt_stack_p!(invalid_opcode, stack, { - println!("\nEXCEPTION: Invalid Opcode"); + error!("\nEXCEPTION: Invalid Opcode"); stack.dump(); loop {} }); @@ -50,23 +50,23 @@ use super::consts::*; interrupt!(keyboard, { use arch::driver::keyboard; - println!("\nInterupt: Keyboard"); + info!("\nInterupt: Keyboard"); let c = keyboard::get(); - println!("Key = '{}' {}", c as u8 as char, c); + info!("Key = '{}' {}", c as u8 as char, c); ack(IRQ_KBD); }); interrupt!(com1, { use arch::driver::serial::COM1; - println!("\nInterupt: COM1"); + info!("\nInterupt: COM1"); COM1.lock().receive(); ack(IRQ_COM1); }); interrupt!(com2, { use arch::driver::serial::COM2; - println!("\nInterupt: COM2"); + info!("\nInterupt: COM2"); COM2.lock().receive(); ack(IRQ_COM2); }); @@ -82,7 +82,7 @@ interrupt_switch!(timer, stack, rsp, { static mut tick: usize = 0; unsafe{ tick += 1; } if tick % 100 == 0 { - println!("\nInterupt: Timer\ntick = {}", tick); + info!("\nInterupt: Timer\ntick = {}", tick); use process; process::schedule(&mut rsp); } @@ -91,7 +91,7 @@ interrupt_switch!(timer, stack, rsp, { interrupt_stack_p!(to_user, stack, { use arch::gdt; - println!("\nInterupt: To User"); + info!("\nInterupt: To User"); let rsp = unsafe{ (stack as *const InterruptStackP).offset(1) } as usize; gdt::set_ring0_rsp(rsp); stack.iret.cs = gdt::UCODE_SELECTOR.0 as usize; @@ -100,22 +100,22 @@ interrupt_stack_p!(to_user, stack, { }); interrupt_stack_p!(to_kernel, stack, { -// println!("rsp @ {:#x}", stack as *const _ as usize); +// info!("rsp @ {:#x}", stack as *const _ as usize); use arch::gdt; - println!("\nInterupt: To Kernel"); + info!("\nInterupt: To Kernel"); stack.iret.cs = gdt::KCODE_SELECTOR.0 as usize; stack.iret.ss = gdt::KDATA_SELECTOR.0 as usize; }); interrupt_switch!(syscall, stack, rsp, { - println!("\nInterupt: Syscall {:#x?}", stack.scratch.rax); + info!("\nInterupt: Syscall {:#x?}", stack.scratch.rax); use syscall::syscall; let ret = syscall(stack, &mut rsp, false); stack.scratch.rax = ret as usize; }); interrupt_switch!(syscall32, stack, rsp, { -// println!("\nInterupt: Syscall {:#x?}", stack.scratch.rax); +// info!("\nInterupt: Syscall {:#x?}", stack.scratch.rax); use syscall::syscall; let ret = syscall(stack, &mut rsp, true); stack.scratch.rax = ret as usize; diff --git a/src/arch/x86_64/paging/cow.rs b/src/arch/x86_64/paging/cow.rs index 30d5ba6..b8ed039 100644 --- a/src/arch/x86_64/paging/cow.rs +++ b/src/arch/x86_64/paging/cow.rs @@ -169,8 +169,6 @@ mod test { use super::*; pub fn test_cow() { - debug!("Testing: Copy on write"); - let mut page_table = unsafe { ActivePageTable::new() }; let frame = alloc_frame(); @@ -208,7 +206,5 @@ mod test { "The last write reference should not allocate new frame."); assert_eq!(unsafe { *(0x1000 as *const u8) }, 2); assert_eq!(unsafe { *(0x2000 as *const u8) }, 3); - - debug!("Success: Copy on write"); } } \ No newline at end of file diff --git a/src/fs.rs b/src/fs.rs index da69a3a..e14fe72 100644 --- a/src/fs.rs +++ b/src/fs.rs @@ -35,7 +35,7 @@ pub fn load_sfs() { let sfs = SimpleFileSystem::open(Box::new(slice)).unwrap(); let root = sfs.root_inode(); let files = root.borrow().list().unwrap(); - debug!("Loading programs: {:?}", files); + trace!("Loading programs: {:?}", files); // for name in files.iter().filter(|&f| f != "." && f != "..") { for name in files.iter().filter(|&f| f == "forktest") { diff --git a/src/io/mod.rs b/src/io/mod.rs index 3944f05..2f3d34b 100644 --- a/src/io/mod.rs +++ b/src/io/mod.rs @@ -3,15 +3,10 @@ use arch::driver::serial::COM1; mod vga_writer; -macro_rules! _debug { - ($($arg:tt)*) => ({ - $crate::io::debug(format_args!($($arg)*)); - }); -} - -macro_rules! debug { - ($fmt:expr) => (_debug!(concat!($fmt, "\n"))); - ($fmt:expr, $($arg:tt)*) => (_debug!(concat!($fmt, "\n"), $($arg)*)); +pub fn init() { + static LOGGER: SimpleLogger = SimpleLogger; + log::set_logger(&LOGGER).unwrap(); + log::set_max_level(LevelFilter::Debug); } macro_rules! print { @@ -25,6 +20,14 @@ macro_rules! println { ($fmt:expr, $($arg:tt)*) => (print!(concat!($fmt, "\n"), $($arg)*)); } +/// Add escape sequence to print with color in Linux console +macro_rules! with_color { + ($args: ident, $color: ident) => {{ + let (show, code) = color_to_console_code($color); + format_args!("{}[{};{}m{}{}[0m", 27 as char, show.clone(), code + 30, $args, 27 as char) + }}; +} + use arch::driver::vga::Color; fn print_in_color(args: fmt::Arguments, color: Color) { @@ -38,19 +41,17 @@ fn print_in_color(args: fmt::Arguments, color: Color) { // TODO: 解决死锁问题 // 若进程在持有锁时被中断，中断处理程序请求输出，就会死锁 unsafe{ COM1.force_unlock(); } - COM1.lock().write_fmt(args).unwrap(); + COM1.lock().write_fmt(with_color!(args, color)).unwrap(); } pub fn print(args: fmt::Arguments) { - print_in_color(args, Color::LightGray); -} - -pub fn debug(args: fmt::Arguments) { - print_in_color(args, Color::LightRed); + use core::fmt::Write; + unsafe { COM1.force_unlock(); } + COM1.lock().write_fmt(args).unwrap(); } pub fn write(fd: usize, base: *const u8, len: usize) -> i32 { - debug!("write: fd: {}, base: {:?}, len: {:#x}", fd, base, len); + info!("write: fd: {}, base: {:?}, len: {:#x}", fd, base, len); use core::slice; use core::str; let slice = unsafe { slice::from_raw_parts(base, len) }; @@ -60,7 +61,7 @@ pub fn write(fd: usize, base: *const u8, len: usize) -> i32 { pub fn open(path: *const u8, flags: usize) -> i32 { let path = unsafe { from_cstr(path) }; - debug!("open: path: {:?}, flags: {:?}", path, flags); + info!("open: path: {:?}, flags: {:?}", path, flags); match path { "stdin:" => 0, "stdout:" => 1, @@ -69,7 +70,7 @@ pub fn open(path: *const u8, flags: usize) -> i32 { } pub fn close(fd: usize) -> i32 { - debug!("close: fd: {:?}", fd); + info!("close: fd: {:?}", fd); 0 } @@ -77,4 +78,55 @@ pub unsafe fn from_cstr(s: *const u8) -> &'static str { use core::{str, slice}; let len = (0usize..).find(|&i| *s.offset(i as isize) == 0).unwrap(); str::from_utf8(slice::from_raw_parts(s, len)).unwrap() +} + +use log; +use log::{Record, Level, Metadata, Log, SetLoggerError, LevelFilter}; + +struct SimpleLogger; + +impl Log for SimpleLogger { + fn enabled(&self, metadata: &Metadata) -> bool { + true +// metadata.level() <= Level::Info + } + fn log(&self, record: &Record) { + if self.enabled(record.metadata()) { + print_in_color(format_args!("{}\n", record.args()), Color::from(record.level())); + } + } + fn flush(&self) {} +} + +impl From for Color { + fn from(level: Level) -> Self { + match level { + Level::Error => Color::Red, + Level::Warn => Color::Yellow, + Level::Info => Color::Blue, + Level::Debug => Color::LightRed, + Level::Trace => Color::DarkGray, + } + } +} + +fn color_to_console_code(color: Color) -> (u8, u8) { + match color { + Color::Black => (0, 0), + Color::Blue => (0, 4), + Color::Green => (0, 2), + Color::Cyan => (0, 6), + Color::Red => (0, 1), + Color::Magenta => (0, 5), + Color::Brown => (0, 3), + Color::LightGray => (1, 7), + Color::DarkGray => (0, 7), + Color::LightBlue => (1, 4), + Color::LightGreen => (1, 2), + Color::LightCyan => (1, 6), + Color::LightRed => (1, 1), + Color::Pink => (1, 5), + Color::Yellow => (1, 3), + Color::White => (1, 0), + } } \ No newline at end of file diff --git a/src/lib.rs b/src/lib.rs index 181b54b..3b45caf 100644 --- a/src/lib.rs +++ b/src/lib.rs @@ -34,6 +34,8 @@ extern crate bit_field; extern crate syscall as redox_syscall; extern crate xmas_elf; extern crate arrayvec; +#[macro_use] +extern crate log; extern crate simple_filesystem; #[macro_use] // print! @@ -57,6 +59,7 @@ mod arch; #[no_mangle] pub extern "C" fn rust_main(multiboot_information_address: usize) -> ! { arch::cpu::init(); + io::init(); // ATTENTION: we have a very small stack and no guard page println!("Hello World{}", "!"); @@ -69,8 +72,7 @@ pub extern "C" fn rust_main(multiboot_information_address: usize) -> ! { arch::gdt::init(); arch::idt::init(); - arch::paging::test_cow(); - + test!(cow); test!(global_allocator); test!(guard_page); test!(find_mp); @@ -161,4 +163,9 @@ mod test { println!("It did not crash!"); } + + pub fn cow() { + use arch; + arch::paging::test_cow(); + } } \ No newline at end of file diff --git a/src/memory/mod.rs b/src/memory/mod.rs index 676c23f..2dd81af 100644 --- a/src/memory/mod.rs +++ b/src/memory/mod.rs @@ -36,7 +36,7 @@ pub fn page_fault_handler(addr: VirtAddr) -> bool { pub fn init(boot_info: BootInformation) -> MemoryController { assert_has_not_been_called!("memory::init must be called only once"); - debug!("{:?}", boot_info); + info!("{:?}", boot_info); let memory_map_tag = boot_info.memory_map_tag().expect( "Memory map tag required"); diff --git a/src/memory/stack_allocator.rs b/src/memory/stack_allocator.rs index d4cba16..bc73bc2 100644 --- a/src/memory/stack_allocator.rs +++ b/src/memory/stack_allocator.rs @@ -84,6 +84,6 @@ impl Stack { impl Drop for Stack { fn drop(&mut self) { - debug!("WARNING: stack leak: {:#x?}", self); + warn!("stack leak: {:#x?}", self); } } \ No newline at end of file diff --git a/src/process/mod.rs b/src/process/mod.rs index 7040544..fe93c1f 100644 --- a/src/process/mod.rs +++ b/src/process/mod.rs @@ -54,13 +54,12 @@ pub fn sys_fork(tf: &TrapFrame) -> i32 { let mut mc = MC.try().unwrap().lock(); let new = processor.current().fork(tf, &mut mc); let pid = processor.add(new); - debug!("fork: {}", pid); + info!("fork: {} -> {}", processor.current().pid, pid); pid as i32 } /// Wait the process exit. Return the exit code. pub fn sys_wait(rsp: &mut usize, pid: usize) -> i32 { - debug!("wait: {}", pid); let mut processor = PROCESSOR.try().unwrap().lock(); let target = match pid { 0 => WaitTarget::AnyChild, diff --git a/src/process/process.rs b/src/process/process.rs index 208d3b6..b4ed3f5 100644 --- a/src/process/process.rs +++ b/src/process/process.rs @@ -89,7 +89,7 @@ impl Process { memory_set.push(MemoryArea::new(user_stack_buttom, user_stack_top, EntryFlags::WRITABLE | EntryFlags::NO_EXECUTE | EntryFlags::USER_ACCESSIBLE, "user_stack")); let page_table = mc.make_page_table(&memory_set); -// debug!("{:#x?}", memory_set); + trace!("{:#x?}", memory_set); let entry_addr = match elf.header.pt2 { HeaderPt2::Header32(header) => header.entry_point as usize, @@ -120,7 +120,7 @@ impl Process { let kstack = mc.alloc_stack(7).unwrap(); let tf = TrapFrame::new_user_thread(entry_addr, user_stack_top - 8, is32); let rsp = kstack.push_at_top(tf); -// debug!("rsp = {:#x}", rsp); + trace!("rsp = {:#x}", rsp); Process { pid: 0, diff --git a/src/process/processor.rs b/src/process/processor.rs index b476bf1..b2bc370 100644 --- a/src/process/processor.rs +++ b/src/process/processor.rs @@ -81,7 +81,7 @@ impl Processor { from.page_table = Some(old_table); } - debug!("Processor: switch from {} to {}\n rsp: {:#x} -> {:#x}", pid0, pid, rsp0, rsp); + info!("Processor: switch from {} to {}\n rsp: {:#x} -> {:#x}", pid0, pid, rsp0, rsp); } fn get(&self, pid: Pid) -> &Process { @@ -108,7 +108,7 @@ impl Processor { pub fn exit(&mut self, pid: Pid, error_code: ErrorCode) { assert_ne!(pid, self.current_pid); - debug!("Processor: {} exit, code: {}", pid, error_code); + info!("Processor: {} exit, code: {}", pid, error_code); self.get_mut(pid).status = Status::Exited(error_code); if let Some(waiter) = self.find_waiter(pid) { { @@ -116,7 +116,7 @@ impl Processor { p.status = Status::Ready; p.set_return_value(error_code); } - debug!("Processor: remove {}", pid); + info!("Processor: remove {}", pid); self.procs.remove(&pid); } } @@ -139,11 +139,11 @@ impl Processor { WaitTarget::Proc(pid) => (pid, self.get(pid).exit_code()), }; if let Some(exit_code) = exit_code { - debug!("Processor: remove {}", pid); + info!("Processor: {} wait find and remove {}", self.current_pid, pid); self.procs.remove(&pid); WaitResult::Ok(exit_code) } else { - debug!("Processor: {} wait for {}", self.current_pid, pid); + info!("Processor: {} wait for {}", self.current_pid, pid); let current_pid = self.current_pid; self.get_mut(current_pid).status = Status::Sleeping(pid); WaitResult::Blocked diff --git a/src/syscall.rs b/src/syscall.rs index a6546fc..aa2690c 100644 --- a/src/syscall.rs +++ b/src/syscall.rs @@ -37,7 +37,7 @@ pub unsafe fn syscall(tf: &TrapFrame, rsp: &mut usize, is32: bool) -> i32 { 0 }, _ => { - debug!("unknown syscall {:#x?}", id); + warn!("unknown syscall {:#x?}", id); -1 }, }