Update log levels.

5 files changed, 68 insertions, 58 deletions

diff --git a/app/Cargo.toml b/app/Cargo.toml
index 09900f9..1bf5ab8 100644
--- a/app/Cargo.toml
+++ b/app/Cargo.toml
@@ -21,7 +21,7 @@ nb = "~0.1"
 cortex-m = "~0.6"
 cortex-m-rt = "~0.6"
 embedded-hal = "~0.2"
-log = "~0.4"
+log = { version = "~0.4", features = ["max_level_trace", "release_max_level_warn"] }
 
 [features]
 default = ["cortex-m/const-fn"]
diff --git a/app/src/logger.rs b/app/src/logger.rs
index 140eebe..5ef08f7 100644
--- a/app/src/logger.rs
+++ b/app/src/logger.rs
@@ -3,7 +3,7 @@ use rb::{Reader, RingBuffer, Writer};
 use core::cell::UnsafeCell;
 use core::fmt::{self, Write};
 use embedded_hal::{digital::v2::OutputPin, serial};
-use log::{Level, Metadata, Record};
+use log::{Metadata, Record};
 use trinket_m0::{
     gpio::{Pa6, Pa7, PfD},
     sercom::{Sercom0Pad2, Sercom0Pad3, UART0},
@@ -83,7 +83,7 @@ where
     L: OutputPin + Send + Sync,
 {
     fn enabled(&self, metadata: &Metadata) -> bool {
-        metadata.level() <= Level::Info
+        metadata.level() <= log::max_level()
     }
 
     fn log(&self, record: &Record) {
diff --git a/app/src/main.rs b/app/src/main.rs
index 792f339..d091a9e 100755
--- a/app/src/main.rs
+++ b/app/src/main.rs
@@ -16,7 +16,7 @@ use clint::HandlerArray;
 use cortex_m::asm::wfi;
 use cortex_m_rt::{entry, exception, ExceptionFrame};
 use embedded_hal::digital::v2::OutputPin;
-use log::{info, LevelFilter};
+use log::{debug, info, LevelFilter};
 use smart_leds::colors;
 use smart_leds_trait::SmartLedsWrite;
 use trinket_m0::{
@@ -130,7 +130,7 @@ fn main() -> ! {
             let tick = rtc::millis();
             if tick >= last_tick + 1_024 {
                 last_tick = tick;
-                // info!("{}: tick\r\n", rtc::millis());
+                // trace!("{}: tick\r\n", rtc::millis());
             }
 
             usb_host.task();
@@ -177,7 +177,7 @@ fn DefaultHandler(interrupt: i16) {
     let red_led: &mut Pa10<Output<OpenDrain>> = unsafe { core::mem::transmute(LED) };
     red_led.set_high().ok();
 
-    info!("*** Default Handler: {} ***", interrupt);
+    debug!("*** Default Handler: {} ***", interrupt);
 }
 
 #[exception]
@@ -185,7 +185,7 @@ fn NonMaskableInt() {
     let red_led: &mut Pa10<Output<OpenDrain>> = unsafe { core::mem::transmute(LED) };
     red_led.set_high().ok();
 
-    info!("+++ NonMaskableInt +++");
+    debug!("+++ NonMaskableInt +++");
 }
 
 #[exception]
@@ -193,7 +193,7 @@ fn SVCall() {
     let red_led: &mut Pa10<Output<OpenDrain>> = unsafe { core::mem::transmute(LED) };
     red_led.set_high().ok();
 
-    info!("+++ SVCall +++");
+    debug!("+++ SVCall +++");
 }
 
 #[exception]
@@ -201,7 +201,7 @@ fn PendSV() {
     let red_led: &mut Pa10<Output<OpenDrain>> = unsafe { core::mem::transmute(LED) };
     red_led.set_high().ok();
 
-    info!("+++ PendSV +++");
+    debug!("+++ PendSV +++");
 }
 
 #[exception]
@@ -209,7 +209,7 @@ fn SysTick() {
     let red_led: &mut Pa10<Output<OpenDrain>> = unsafe { core::mem::transmute(LED) };
     red_led.set_high().ok();
 
-    info!("+++ SysTick +++");
+    debug!("+++ SysTick +++");
 }
 
 #[interrupt]
diff --git a/usbh/src/lib.rs b/usbh/src/lib.rs
index a38ae87..8213eb5 100755
--- a/usbh/src/lib.rs
+++ b/usbh/src/lib.rs
@@ -15,7 +15,7 @@ use atsamd_hal::{
     target_device::{PM, USB},
 };
 use embedded_hal::digital::v2::OutputPin;
-use log::{info, warn};
+use log::{debug, error, trace, warn};
 
 #[derive(Clone, Copy, Debug, PartialEq)]
 pub enum Event {
@@ -170,7 +170,6 @@ where
             rc.host_enable_pin = Some(he_pin.into_open_drain_output(port));
         }
 
-        info!("setting up usb clock");
         pm.apbbmask.modify(|_, w| w.usb_().set_bit());
 
         // Set up USB clock from 48MHz source on generic clock 6.
@@ -185,7 +184,7 @@ where
     }
 
     pub fn reset_periph(&mut self) {
-        info!("resetting usb");
+        debug!("resetting usb");
         // Reset the USB peripheral and wait for sync.
         self.usb.host().ctrla.write(|w| w.swrst().set_bit());
         while self.usb.host().syncbusy.read().swrst().bit_is_set() {}
@@ -233,14 +232,14 @@ where
 
         // Set VBUS OK to allow host operation.
         self.usb.host().ctrlb.modify(|_, w| w.vbusok().set_bit());
-        info!("...done");
+        debug!("...done");
     }
 
     pub fn task(&mut self) {
         static mut LAST_EVENT: Event = Event::Error;
         unsafe {
             if LAST_EVENT != LATEST_EVENT {
-                info!("new event: {:?}", LATEST_EVENT);
+                trace!("new event: {:?}", LATEST_EVENT);
             }
         }
 
@@ -270,9 +269,12 @@ where
         let bits = self.usb.host().intflag.read().bits();
         unsafe {
             if LAST_CBITS != cbits || LAST_FLAGS != bits || LAST_TASK_STATE != self.task_state {
-                info!(
+                trace!(
                     "cb: {:x}, f: {:x} changing state {:?} -> {:?}",
-                    cbits, bits, LAST_TASK_STATE, self.task_state,
+                    cbits,
+                    bits,
+                    LAST_TASK_STATE,
+                    self.task_state,
                 );
             }
             LAST_CBITS = cbits;
@@ -281,7 +283,7 @@ where
         };
 
         if let Some(_event) = self.events.shift() {
-            // info!("Found event: {:?}", event);
+            // trace!("Found event: {:?}", event);
             // self.task_state = match event {
             //     Event::None => TaskState::Detached(DetachedState::Illegal),
             //     Event::Detached => {
@@ -352,7 +354,7 @@ where
 
             AttachedState::WaitResetComplete => {
                 if self.usb.host().intflag.read().rst().bit_is_set() {
-                    info!("reset was sent");
+                    trace!("reset was sent");
                     self.usb.host().intflag.write(|w| w.rst().set_bit());
 
                     // Make sure we always have a control pipe set up.
@@ -413,12 +415,13 @@ where
         )?;
 
         let desc = vol_descr.get();
-        info!(" -- devDesc: {:?}", desc);
+        trace!(" -- devDesc: {:?}", desc);
 
         // Assign address to this device and:
         //  - Stash bMaxPacketSize
         // Then SET_ADDRESS(newAddr)
         let new_address: u8 = 1;
+        debug!("Setting address to {}.", new_address);
         self.control_req(
             0,
             0,
@@ -428,12 +431,11 @@ where
             0,
             None,
         )?;
-        info!(" -- address set");
         // Delay according to §9.2.6.3 of USB 2.0
         let until = (self.millis)() + 300;
         while (self.millis)() < until {}
 
-        info!("getting config with array");
+        debug!("getting config with array");
         //let tmp: USBConfigurationDescriptor = Default::default();
         let mut tmp: [u8; 9] = [0; 9];
         //let vol_descr = ::vcell::VolatileCell::new(tmp);
@@ -448,10 +450,10 @@ where
         )?;
 
         //let desc = vol_descr.get();
-        info!("cdesc.len: {}, type: {}", tmp[0], tmp[1]);
+        debug!("cdesc.len: {}, type: {}", tmp[0], tmp[1]);
 
         // Once addressed, SET_CONFIGURATION(0)
-        info!("+++ setting configuration");
+        debug!("+++ setting configuration");
         let conf: u8 = 0;
         self.control_req(
             new_address,
@@ -462,7 +464,7 @@ where
             0,
             None,
         )?;
-        info!(" -- configuration set");
+        debug!(" -- configuration set");
 
         // Now we should be able to access it normally.
 
@@ -511,13 +513,13 @@ where
         if let Some(b) = buf {
             match bm_request_type.direction() {
                 USBSetupDirection::DeviceToHost => {
-                    info!("buf0: {:?}", &b);
+                    trace!("buf0: {:?}", &b);
                     pipe.in_transfer(&b, NAK_LIMIT, self.millis)?;
-                    info!("buf1: {:?}", &b);
+                    trace!("buf1: {:?}", &b);
                 }
 
                 USBSetupDirection::HostToDevice => {
-                    info!("Should OUT for {}b", b.len);
+                    debug!("Should OUT for {}b", b.len);
                 }
             }
         }
@@ -541,7 +543,7 @@ where
 
         // TODO: should probably make `pipe.send` have optional
         // `DataBuf`, rather than exposing `dispatch_retries`.
-        info!("dispatching status stage");
+        trace!("dispatching status stage");
         pipe.dispatch_retries(token, NAK_LIMIT, self.millis)?;
         Ok(())
     }
@@ -565,36 +567,36 @@ pub fn handler(usbp: usize, events: &mut EventWriter) {
     let usb: &mut USB = unsafe { core::mem::transmute(usbp) };
     let flags = usb.host().intflag.read();
 
-    info!("USB - {:x}", flags.bits());
+    trace!("USB - {:x}", flags.bits());
 
     let mut unshift_event = |e: Event| {
         unsafe { LATEST_EVENT = e };
         if let Err(_) = events.unshift(e) {
-            info!("Couldn't write USB event to queue.");
+            error!("Couldn't write USB event to queue.");
         }
     };
 
     if flags.hsof().bit_is_set() {
-        info!(" +hsof");
+        trace!(" +hsof");
         usb.host().intflag.write(|w| w.hsof().set_bit());
         unshift_event(Event::Attached);
     }
 
     if flags.rst().bit_is_set() {
         // We seem to get this whenever a device attaches/detaches.
-        info!(" +rst");
+        trace!(" +rst");
         usb.host().intflag.write(|w| w.rst().set_bit());
         unshift_event(Event::Detached);
     }
 
     if flags.uprsm().bit_is_set() {
-        info!(" +uprsm");
+        trace!(" +uprsm");
         usb.host().intflag.write(|w| w.uprsm().set_bit());
         unshift_event(Event::Detached);
     }
 
     if flags.dnrsm().bit_is_set() {
-        info!(" +dnrsm");
+        trace!(" +dnrsm");
         usb.host().intflag.write(|w| w.dnrsm().set_bit());
         unshift_event(Event::Detached);
     }
@@ -602,19 +604,19 @@ pub fn handler(usbp: usize, events: &mut EventWriter) {
     if flags.wakeup().bit_is_set() {
         // §32.8.5.8 - since VBUSOK is set, then this happens when a
         // device is connected.
-        info!(" +wakeup");
+        trace!(" +wakeup");
         usb.host().intflag.write(|w| w.wakeup().set_bit());
         unshift_event(Event::Attached);
     }
 
     if flags.ramacer().bit_is_set() {
-        info!(" +ramacer");
+        trace!(" +ramacer");
         usb.host().intflag.write(|w| w.ramacer().set_bit());
         unshift_event(Event::Detached);
     }
 
     if flags.dconn().bit_is_set() {
-        info!(" +dconn");
+        trace!(" +dconn");
         usb.host().intflag.write(|w| w.dconn().set_bit());
         usb.host().intenclr.write(|w| w.dconn().set_bit());
         usb.host().intflag.write(|w| w.ddisc().set_bit());
@@ -624,7 +626,7 @@ pub fn handler(usbp: usize, events: &mut EventWriter) {
     }
 
     if flags.ddisc().bit_is_set() {
-        info!(" +ddisc");
+        trace!(" +ddisc");
         usb.host().intflag.write(|w| w.ddisc().set_bit());
         usb.host().intenclr.write(|w| w.ddisc().set_bit());
         //			// Stop reset signal, in case of disconnection during reset
diff --git a/usbh/src/pipe.rs b/usbh/src/pipe.rs
index d880d7a..833ddea 100644
--- a/usbh/src/pipe.rs
+++ b/usbh/src/pipe.rs
@@ -13,7 +13,7 @@ use status_bk::StatusBk;
 use status_pipe::StatusPipe;
 
 use core::convert::TryInto;
-use log::info;
+use log::trace;
 
 use atsamd_hal::target_device::usb::{
     self,
@@ -65,13 +65,11 @@ impl PipeTable {
         let pregs = PipeRegs::from(host, i);
         let pdesc = &mut self.tbl[i];
 
-        info!("setting paddr of pipe {} to {}:{}", i, addr, ep);
-        info!("cpipe0: {:x}", pdesc.bank0.ctrl_pipe.read().bits());
+        trace!("setting paddr of pipe {} to {}:{}", i, addr, ep);
         pdesc.bank0.ctrl_pipe.write(|w| {
             w.pdaddr().set_addr(addr);
             w.pepnum().set_epnum(ep)
         });
-        info!("cpipe1: {:x}", pdesc.bank0.ctrl_pipe.read().bits());
         Pipe {
             num: i,
             regs: pregs,
@@ -99,7 +97,7 @@ impl Pipe<'_, '_> {
         // byte_count section of register is 14 bits.
         assert!(buf.len < 16_384);
 
-        info!("p{}: sending {:?}", self.num, buf);
+        trace!("p{}: sending {:?}", self.num, buf);
 
         self.desc
             .bank0
@@ -125,7 +123,7 @@ impl Pipe<'_, '_> {
         // byte_count section of register is 14 bits.
         assert!(buf.len < 16_384);
 
-        info!("p{}: Should IN for {}b.", self.num, buf.len);
+        trace!("p{}: Should IN for {}b.", self.num, buf.len);
         self.desc.bank0.pcksize.write(|w| {
             unsafe { w.byte_count().bits(buf.len as u16) };
             unsafe { w.multi_packet_size().bits(0) }
@@ -146,7 +144,7 @@ impl Pipe<'_, '_> {
             self.dispatch_retries(USBToken::In, nak_limit, millis)?;
             bytes_received += self.desc.bank0.pcksize.read().byte_count().bits() as usize;
             assert!(bytes_received <= buf.len);
-            info!("!! read {} of {}", bytes_received, buf.len);
+            trace!("!! read {} of {}", bytes_received, buf.len);
         }
         self.regs.statusset.write(|w| w.pfreeze().set_bit());
 
@@ -169,14 +167,14 @@ impl Pipe<'_, '_> {
     ) -> Result<(), PipeErr> {
         assert!(retries > 0);
 
-        info!("initial regs");
+        trace!("initial regs");
         self.log_regs();
 
         let until = millis() + USB_TIMEOUT;
         let mut last_result: Result<(), PipeErr> = Err(PipeErr::SWTimeout);
         let mut naks = 0;
         while naks <= retries {
-            info!("p{}: dispatch {:?} retry {}", self.num, token, naks);
+            trace!("p{}: dispatch {:?} retry {}", self.num, token, naks);
 
             self.dispatch_packet(token);
             last_result = self.dispatch_result(token, until, millis);
@@ -208,9 +206,13 @@ impl Pipe<'_, '_> {
         let bin = self.regs.binterval.read().bits();
         let sts = self.regs.status.read().bits();
         let ifl = self.regs.intflag.read().bits();
-        info!(
+        trace!(
             "p{}: cfg: {:x}, bin: {:x}, sts: {:x}, ifl: {:x}",
-            self.num, cfg, bin, sts, ifl
+            self.num,
+            cfg,
+            bin,
+            sts,
+            ifl
         );
 
         // Pipe RAM regs
@@ -220,9 +222,15 @@ impl Pipe<'_, '_> {
         let sbk = self.desc.bank0.status_bk.read().bits();
         let hcp = self.desc.bank0.ctrl_pipe.read().bits();
         let spi = self.desc.bank0.status_pipe.read().bits();
-        info!(
+        trace!(
             "p{}: adr: {:x}, pks: {:x}, ext: {:x}, sbk: {:x}, hcp: {:x}, spi: {:x}",
-            self.num, adr, pks, ext, sbk, hcp, spi
+            self.num,
+            adr,
+            pks,
+            ext,
+            sbk,
+            hcp,
+            spi
         );
     }
 
@@ -255,17 +263,17 @@ impl Pipe<'_, '_> {
             if self.is_transfer_complete(token)? {
                 return Ok(());
             } else if self.regs.intflag.read().stall().bit_is_set() {
-                info!("stall");
+                trace!("stall");
                 self.log_regs();
                 self.regs.intflag.write(|w| w.stall().set_bit());
                 return Err(PipeErr::Stall);
             } else if self.regs.intflag.read().trfail().bit_is_set() {
-                info!("trfail");
+                trace!("trfail");
                 self.log_regs();
                 self.regs.intflag.write(|w| w.trfail().set_bit());
                 return Err(PipeErr::TransferFail);
             } else if self.desc.bank0.status_bk.read().errorflow().bit_is_set() {
-                info!("errorflow");
+                trace!("errorflow");
                 self.log_regs();
                 self.desc
                     .bank0
@@ -273,7 +281,7 @@ impl Pipe<'_, '_> {
                     .write(|w| w.errorflow().clear_bit());
                 return Err(PipeErr::Flow);
             } else if self.desc.bank0.status_pipe.read().touter().bit_is_set() {
-                info!("touter");
+                trace!("touter");
                 self.log_regs();
                 self.desc
                     .bank0
@@ -281,7 +289,7 @@ impl Pipe<'_, '_> {
                     .write(|w| w.touter().clear_bit());
                 return Err(PipeErr::HWTimeout);
             } else if self.desc.bank0.status_pipe.read().dtgler().bit_is_set() {
-                info!("dtgler");
+                trace!("dtgler");
                 self.log_regs();
                 self.desc
                     .bank0
@@ -290,7 +298,7 @@ impl Pipe<'_, '_> {
                 return Err(PipeErr::DataToggle);
             }
         }
-        info!("swtimeout");
+        trace!("swtimeout");
         self.log_regs();
         Err(PipeErr::SWTimeout)
     }