Add logging capability.

Cargo.toml

@@ -6,8 +6,13 @@ license = "0BSD"
 
 [dependencies]
 byteorder = { version = "0.5", default-features = false }
+log = { version = "0.3", optional = true }
 libc = { version = "0.2.18", optional = true }
 
+[dev-dependencies]
+env_logger = "0.3"
+
 [features]
 std = ["libc"]
-default = ["std"]
+logging = ["log"]
+default = ["std", "logging"]

examples/smoltcpserver.rs

@@ -1,7 +1,14 @@
 #![feature(associated_consts, type_ascription)]
+#[macro_use]
+extern crate log;
+extern crate env_logger;
 extern crate smoltcp;
 
 use std::env;
+use std::time::Instant;
+use log::{LogLevelFilter, LogRecord};
+use env_logger::{LogBuilder};
+
 use smoltcp::Error;
 use smoltcp::phy::{Tracer, TapInterface};
 use smoltcp::wire::{EthernetFrame, EthernetAddress, IpAddress, IpEndpoint};
@@ -11,6 +18,18 @@ use smoltcp::socket::{UdpSocket, UdpSocketBuffer, UdpPacketBuffer};
 use smoltcp::socket::{TcpSocket, TcpSocketBuffer};
 
 fn main() {
+    let startup_time = Instant::now();
+    LogBuilder::new()
+        .format(move |record: &LogRecord| {
+            let elapsed = Instant::now().duration_since(startup_time);
+            format!("[{:6}.{:03}ms] ({}): {}",
+                    elapsed.as_secs(), elapsed.subsec_nanos() / 1000000,
+                    record.target().replace("smoltcp::", ""), record.args())
+        })
+        .filter(None, LogLevelFilter::Trace)
+        .init()
+        .unwrap();
+
     let ifname = env::args().nth(1).unwrap();
 
     let device = TapInterface::new(ifname.as_ref()).unwrap();
@@ -37,21 +56,21 @@ fn main() {
     loop {
         match iface.poll() {
             Ok(()) => (),
-            Err(e) => println!("error {}", e)
+            Err(e) => debug!("error {}", e)
         }
 
         {
             let udp_socket: &mut UdpSocket = iface.sockets()[0].as_socket();
             let udp_client = match udp_socket.recv() {
                 Ok((endpoint, data)) => {
-                    println!("data {:?} from {}", data, endpoint);
+                    debug!("data {:?} from {}", data, endpoint);
                     Some(endpoint)
                 }
                 Err(Error::Exhausted) => {
                     None
                 }
                 Err(e) => {
-                    println!("error {}", e);
+                    debug!("error {}", e);
                     None
                 }
             };

src/lib.rs

@@ -1,4 +1,4 @@
-#![feature(associated_consts, const_fn, step_by, intrinsics)]
+#![feature(associated_consts, const_fn, step_by, intrinsics, slice_patterns)]
 #![no_std]
 
 extern crate byteorder;
@@ -8,6 +8,16 @@ extern crate byteorder;
 extern crate std;
 #[cfg(feature = "std")]
 extern crate libc;
+#[cfg(feature = "logging")]
+#[macro_use(trace, log)]
+extern crate log;
+
+macro_rules! net_trace {
+    ($($arg:tt)*) => {
+        #[cfg(feature = "logging")]
+        trace!($($arg)*)
+    }
+}
 
 use core::fmt;
 

src/socket/tcp.rs

@@ -185,15 +185,29 @@ impl<'a> TcpSocket<'a> {
         self.remote_end
     }
 
+    fn set_state(&mut self, state: State) {
+        if self.state != state {
+            if self.remote_end.addr.is_unspecified() {
+                net_trace!("tcp:{}: state={}→{}",
+                           self.local_end, self.state, state);
+            } else {
+                net_trace!("tcp:{}:{}: state={}→{}",
+                           self.local_end, self.remote_end, self.state, state);
+            }
+        }
+        self.state = state
+    }
+
     /// Start listening on the given endpoint.
     ///
     /// # Panics
     /// This function will panic if the socket is not in the CLOSED state.
     pub fn listen(&mut self, endpoint: IpEndpoint) {
         assert!(self.state == State::Closed);
-        self.state      = State::Listen;
+
         self.local_end  = endpoint;
-        self.remote_end = IpEndpoint::default()
+        self.remote_end = IpEndpoint::default();
+        self.set_state(State::Listen);
     }
 
     /// See [Socket::collect](enum.Socket.html#method.collect).
@@ -220,12 +234,13 @@ impl<'a> TcpSocket<'a> {
             (State::Listen, TcpRepr {
                 src_port, dst_port, control: TcpControl::Syn, seq_number, ack_number: None, ..
             }) => {
-                self.state         = State::SynReceived;
                 self.local_end     = IpEndpoint::new(*dst_addr, dst_port);
                 self.remote_end    = IpEndpoint::new(*src_addr, src_port);
                 self.remote_seq_no = seq_number;
                 // FIXME: use something more secure
                 self.local_seq_no  = !seq_number;
+                self.set_state(State::SynReceived);
+
                 // FIXME: queue data from SYN
                 self.retransmit.reset();
                 Ok(())
@@ -264,6 +279,8 @@ impl<'a> TcpSocket<'a> {
                 repr.control    = TcpControl::Syn;
                 repr.seq_number = self.local_seq_no;
                 repr.ack_number = Some(self.remote_seq_no + 1);
+                net_trace!("tcp:{}:{}: SYN sent",
+                           self.local_end, self.remote_end);
             }
             _ => unreachable!()
         }

src/socket/udp.rs

@@ -131,6 +131,8 @@ impl<'a, 'b> UdpSocket<'a, 'b> {
         let packet_buf = try!(self.tx_buffer.enqueue());
         packet_buf.endpoint = endpoint;
         packet_buf.size = size;
+        net_trace!("udp:{}:{}: send {} octets",
+                   self.endpoint, packet_buf.endpoint, packet_buf.size);
         Ok(&mut packet_buf.as_mut()[..size])
     }
 
@@ -148,6 +150,8 @@ impl<'a, 'b> UdpSocket<'a, 'b> {
     /// This function returns `Err(Error::Exhausted)` if the receive buffer is empty.
     pub fn recv(&mut self) -> Result<(IpEndpoint, &[u8]), Error> {
         let packet_buf = try!(self.rx_buffer.dequeue());
+        net_trace!("udp:{}:{}: recv {} octets",
+                   self.endpoint, packet_buf.endpoint, packet_buf.size);
         Ok((packet_buf.endpoint, &packet_buf.as_ref()[..packet_buf.size]))
     }
 
@@ -181,6 +185,8 @@ impl<'a, 'b> UdpSocket<'a, 'b> {
         packet_buf.endpoint = IpEndpoint { addr: *src_addr, port: repr.src_port };
         packet_buf.size = repr.payload.len();
         packet_buf.as_mut()[..repr.payload.len()].copy_from_slice(repr.payload);
+        net_trace!("udp:{}:{}: collect {} octets",
+                   self.endpoint, packet_buf.endpoint, packet_buf.size);
         Ok(())
     }
 
@@ -189,6 +195,8 @@ impl<'a, 'b> UdpSocket<'a, 'b> {
                                              IpProtocol, &PacketRepr) -> Result<(), Error>)
             -> Result<(), Error> {
         let packet_buf = try!(self.tx_buffer.dequeue());
+        net_trace!("udp:{}:{}: dispatch {} octets",
+                   self.endpoint, packet_buf.endpoint, packet_buf.size);
         f(&self.endpoint.addr,
           &packet_buf.endpoint.addr,
           IpProtocol::Udp,