From 1ec7af966fc0be5353e9c588b631a3e2618e2080 Mon Sep 17 00:00:00 2001 From: Brian Cully Date: Thu, 25 Jul 2019 17:20:31 -0400 Subject: Update log levels. --- app/Cargo.toml | 2 +- app/src/logger.rs | 4 ++-- app/src/main.rs | 14 ++++++------- usbh/src/lib.rs | 60 ++++++++++++++++++++++++++++--------------------------- usbh/src/pipe.rs | 46 ++++++++++++++++++++++++------------------ 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> = 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> = 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> = 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> = 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> = 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) } -- cgit v1.2.3