diff --git a/artiq/runtime.rs/Cargo.lock b/artiq/runtime.rs/Cargo.lock index 9fc25d063..5114170b2 100644 --- a/artiq/runtime.rs/Cargo.lock +++ b/artiq/runtime.rs/Cargo.lock @@ -4,6 +4,8 @@ version = "0.0.0" dependencies = [ "byteorder 0.5.3 (registry+https://github.com/rust-lang/crates.io-index)", "fringe 1.1.0 (registry+https://github.com/rust-lang/crates.io-index)", + "log 0.3.6 (registry+https://github.com/rust-lang/crates.io-index)", + "log_buffer 1.0.0 (registry+https://github.com/rust-lang/crates.io-index)", "lwip 0.0.0", "std_artiq 0.0.0", ] @@ -30,6 +32,16 @@ name = "libc" version = "0.2.15" source = "registry+https://github.com/rust-lang/crates.io-index" +[[package]] +name = "log" +version = "0.3.6" +source = "registry+https://github.com/rust-lang/crates.io-index" + +[[package]] +name = "log_buffer" +version = "1.0.0" +source = "registry+https://github.com/rust-lang/crates.io-index" + [[package]] name = "lwip" version = "0.0.0" @@ -53,3 +65,5 @@ dependencies = [ "checksum byteorder 0.5.3 (registry+https://github.com/rust-lang/crates.io-index)" = "0fc10e8cc6b2580fda3f36eb6dc5316657f812a3df879a44a66fc9f0fdbc4855" "checksum fringe 1.1.0 (registry+https://github.com/rust-lang/crates.io-index)" = "987689dcfad85eee8d76b477865641ec483e63fb86d52966bfc350c4a647d78a" "checksum libc 0.2.15 (registry+https://github.com/rust-lang/crates.io-index)" = "23e3757828fa702a20072c37ff47938e9dd331b92fac6e223d26d4b7a55f7ee2" +"checksum log 0.3.6 (registry+https://github.com/rust-lang/crates.io-index)" = "ab83497bf8bf4ed2a74259c1c802351fcd67a65baa86394b6ba73c36f4838054" +"checksum log_buffer 1.0.0 (registry+https://github.com/rust-lang/crates.io-index)" = "f8beb5ba24eca52f9958874445c4de5e086a7e82a1ec6b7ab81e5fcfb134f25a" diff --git a/artiq/runtime.rs/Cargo.toml b/artiq/runtime.rs/Cargo.toml index adc6c37b2..fe5770958 100644 --- a/artiq/runtime.rs/Cargo.toml +++ b/artiq/runtime.rs/Cargo.toml @@ -12,6 +12,8 @@ path = "src/lib.rs" std_artiq = { path = "libstd_artiq" } lwip = { path = "liblwip" } fringe = { version = "= 1.1.0", default-features = false, features = ["alloc"] } +log = { version = "0.3", default-features = false } +log_buffer = { version = "1.0" } byteorder = { version = "0.5", default-features = false } [profile.dev] diff --git a/artiq/runtime.rs/src/buffer_logger.rs b/artiq/runtime.rs/src/buffer_logger.rs new file mode 100644 index 000000000..4ec9927eb --- /dev/null +++ b/artiq/runtime.rs/src/buffer_logger.rs @@ -0,0 +1,57 @@ +use core::mem; +use core::cell::RefCell; +use log::{self, Log, LogMetadata, LogRecord, LogLevelFilter}; +use log_buffer::LogBuffer; + +pub struct BufferLogger { + buffer: RefCell> +} + +// We can never preempt from within the logger, so there can be no data races. +unsafe impl Sync for BufferLogger {} + +impl BufferLogger { + pub fn new(buffer: &'static mut [u8]) -> BufferLogger { + BufferLogger { + buffer: RefCell::new(LogBuffer::new(buffer)) + } + } + + pub fn register(&self, f: F) { + // log::set_logger_raw captures a pointer to ourselves, so we must prevent + // ourselves from being moved or dropped after that function is called (and + // before log::shutdown_logger_raw is called). + unsafe { + log::set_logger_raw(|max_log_level| { + max_log_level.set(LogLevelFilter::Trace); + self as *const Log + }).expect("global logger can only be initialized once"); + } + f(self); + log::shutdown_logger_raw().unwrap(); + } + + pub fn clear(&self) { + self.buffer.borrow_mut().clear() + } + + pub fn extract R>(&self, f: F) -> R { + f(self.buffer.borrow_mut().extract()) + } +} + +impl Log for BufferLogger { + fn enabled(&self, _metadata: &log::LogMetadata) -> bool { + true + } + + fn log(&self, record: &LogRecord) { + if self.enabled(record.metadata()) { + use core::fmt::Write; + writeln!(self.buffer.borrow_mut(), "{}({}): {}", + record.level(), record.location().module_path(), record.args()).unwrap(); + println!("{}({}): {}", + record.level(), record.location().module_path(), record.args()); + } + } +} diff --git a/artiq/runtime.rs/src/io.rs b/artiq/runtime.rs/src/io.rs index a89e2e82f..f48d6d6ff 100644 --- a/artiq/runtime.rs/src/io.rs +++ b/artiq/runtime.rs/src/io.rs @@ -39,7 +39,7 @@ impl Scheduler { Scheduler { threads: Vec::new(), index: 0 } } - pub unsafe fn spawn(&mut self, stack_size: usize, f: F) { + pub unsafe fn spawn(&mut self, stack_size: usize, f: F) { let stack = OwnedStack::new(stack_size); let thread = Thread { generator: Generator::unsafe_new(stack, move |yielder, _| { @@ -286,8 +286,12 @@ impl<'a> Read for TcpStream<'a> { fn read(&mut self, buf: &mut [u8]) -> Result { if self.buffer.is_none() { try!(self.waiter.tcp_readable(&self.lower)); - let pbuf = try!(self.lower.try_read()).unwrap(); - self.buffer = Some((pbuf, 0)) + match self.lower.try_read() { + Ok(Some(pbuf)) => self.buffer = Some((pbuf, 0)), + Ok(None) => unreachable!(), + Err(lwip::Error::ConnectionClosed) => return Ok(0), + Err(err) => return Err(Error::from(err)) + } } let (pbuf, pos) = self.buffer.take().unwrap(); diff --git a/artiq/runtime.rs/src/lib.rs b/artiq/runtime.rs/src/lib.rs index f482efeaa..afb7003c1 100644 --- a/artiq/runtime.rs/src/lib.rs +++ b/artiq/runtime.rs/src/lib.rs @@ -1,12 +1,18 @@ #![no_std] +#![feature(const_fn)] #[macro_use] extern crate std_artiq as std; +#[macro_use] +extern crate log; +extern crate log_buffer; extern crate byteorder; use std::prelude::v1::*; +use buffer_logger::BufferLogger; pub mod io; +pub mod buffer_logger; pub mod session; extern { @@ -16,13 +22,19 @@ extern { #[no_mangle] pub unsafe extern fn rust_main() { - println!("Accepting network sessions in Rust."); - network_init(); + static mut log_buffer: [u8; 4096] = [0; 4096]; + BufferLogger::new(&mut log_buffer[..]) + .register(move |logger| { + info!("Accepting network sessions in Rust."); + network_init(); - let mut scheduler = io::Scheduler::new(); - scheduler.spawn(4096, session::handler); - loop { - lwip_service(); - scheduler.run() - } + let mut scheduler = io::Scheduler::new(); + scheduler.spawn(4096, move |waiter| { + session::handler(waiter, logger) + }); + loop { + lwip_service(); + scheduler.run() + } + }) } diff --git a/artiq/runtime.rs/src/session/mod.rs b/artiq/runtime.rs/src/session/mod.rs index b97af72bf..f4bec57a9 100644 --- a/artiq/runtime.rs/src/session/mod.rs +++ b/artiq/runtime.rs/src/session/mod.rs @@ -1,5 +1,6 @@ use std::prelude::v1::*; -use std::io::{self, Read}; +use std::str; +use std::io::{self, Read, ErrorKind}; use self::protocol::*; mod protocol; @@ -52,15 +53,16 @@ fn check_magic(stream: &mut ::io::TcpStream) -> io::Result<()> { } } -fn handle_request(stream: &mut ::io::TcpStream) -> io::Result<()> { +fn handle_request(stream: &mut ::io::TcpStream, + logger: &::buffer_logger::BufferLogger) -> io::Result<()> { fn read_request(stream: &mut ::io::TcpStream) -> io::Result { let request = try!(Request::read_from(stream)); - println!("comm<-host {:?}", request); + trace!("comm<-host {:?}", request); Ok(request) } fn write_reply(stream: &mut ::io::TcpStream, reply: Reply) -> io::Result<()> { - println!("comm->host {:?}", reply); + trace!("comm->host {:?}", reply); reply.write_to(stream) } @@ -75,28 +77,50 @@ fn handle_request(stream: &mut ::io::TcpStream) -> io::Result<()> { &ident[..ident.iter().position(|&c| c == 0).unwrap()] }; - write_reply(stream, Reply::Ident(ident)) - }, + write_reply(stream, Reply::Ident(str::from_utf8(ident).unwrap())) + } + + Request::Log => { + // Logging the packet with the log is inadvisable + trace!("comm->host Log(...)"); + logger.extract(move |log| { + Reply::Log(log).write_to(stream) + }) + } + + Request::LogClear => { + logger.clear(); + write_reply(stream, Reply::Log("")) + } + _ => unreachable!() } } -fn handle_requests(stream: &mut ::io::TcpStream) -> io::Result<()> { +fn handle_requests(stream: &mut ::io::TcpStream, + logger: &::buffer_logger::BufferLogger) -> io::Result<()> { try!(check_magic(stream)); loop { - try!(handle_request(stream)) + try!(handle_request(stream, logger)) } } -pub fn handler(waiter: ::io::Waiter) { +pub fn handler(waiter: ::io::Waiter, + logger: &::buffer_logger::BufferLogger) { let addr = ::io::SocketAddr::new(::io::IP_ANY, 1381); let listener = ::io::TcpListener::bind(waiter, addr).unwrap(); loop { - let (mut stream, _addr) = listener.accept().unwrap(); - match handle_requests(&mut stream) { + let (mut stream, addr) = listener.accept().unwrap(); + info!("new connection from {:?}", addr); + + match handle_requests(&mut stream, logger) { Ok(()) => (), Err(err) => { - println!("cannot handle network request: {:?}", err); + if err.kind() == ErrorKind::UnexpectedEof { + info!("connection closed"); + } else { + error!("cannot handle network request: {:?}", err); + } } } } diff --git a/artiq/runtime.rs/src/session/protocol.rs b/artiq/runtime.rs/src/session/protocol.rs index cdb27a3f7..deaa2abdd 100644 --- a/artiq/runtime.rs/src/session/protocol.rs +++ b/artiq/runtime.rs/src/session/protocol.rs @@ -177,7 +177,7 @@ impl Request { pub enum Reply<'a> { Log(&'a str), - Ident(&'a [u8]), + Ident(&'a str), ClockSwitchCompleted, ClockSwitchFailed, @@ -213,7 +213,7 @@ impl<'a> Reply<'a> { Reply::Ident(ident) => { try!(write_u8(&mut buf, 2)); try!(buf.write(b"AROR")); - try!(buf.write(ident)); + try!(buf.write(ident.as_bytes())); }, Reply::ClockSwitchCompleted => { try!(write_u8(&mut buf, 3));