libboard_zynq: use log logging

experiments/src/main.rs

@@ -44,7 +44,7 @@ pub fn main_core0() {
     #[cfg(feature = "target_cora_z7_10")]
     const CPU_FREQ: u32 = 650_000_000;
 
-    println!("Setup clock sources...");
+    info!("Setup clock sources...");
     ArmPll::setup(2 * CPU_FREQ);
     Clocks::set_cpu_freq(CPU_FREQ);
     #[cfg(feature = "target_zc706")]
@@ -52,9 +52,9 @@ pub fn main_core0() {
         IoPll::setup(1_000_000_000);
         libboard_zynq::stdio::drop_uart();
     }
-    println!("PLLs set up");
+    info!("PLLs set up");
     let clocks = zynq::clocks::Clocks::get();
-    println!("CPU Clocks: {}/{}/{}/{}", clocks.cpu_6x4x(), clocks.cpu_3x2x(), clocks.cpu_2x(), clocks.cpu_1x());
+    info!("CPU Clocks: {}/{}/{}/{}", clocks.cpu_6x4x(), clocks.cpu_3x2x(), clocks.cpu_2x(), clocks.cpu_1x());
 
     let mut flash = zynq::flash::Flash::new(200_000_000).linear_addressing_mode();
     let flash_ram: &[u8] = unsafe { core::slice::from_raw_parts(flash.ptr(), flash.size()) };
@@ -223,7 +223,7 @@ pub fn main_core0() {
             let timestamp = timer.get_us();
             let seconds   = timestamp / 1_000_000;
             let micros    = timestamp % 1_000_000;
-            println!("time: {:6}.{:06}s", seconds, micros);
+            info!("time: {:6}.{:06}s", seconds, micros);
         }
     });
 

libboard_zynq/src/clocks/source.rs

@@ -1,3 +1,4 @@
+use log::debug;
 use libregister::{RegisterR, RegisterW, RegisterRW};
 use super::slcr;
 
@@ -48,6 +49,8 @@ pub trait ClockSource {
         u32::from(pll_ctrl.read().pll_fdiv()) * PS_CLK
     }
 
+    fn name() -> &'static str;
+
     /// Zynq-7000 AP SoC Technical Reference Manual:
     /// 25.10.4 PLLs
     fn setup(target_freq: u32) {
@@ -58,6 +61,7 @@ pub trait ClockSource {
             .expect("PLL_FDIV_LOCK_PARAM")
             .1.clone();
 
+        debug!("Set {} to {} Hz", Self::name(), target_freq);
         slcr::RegisterBlock::unlocked(|slcr| {
             let (pll_ctrl, pll_cfg, pll_status) = Self::pll_regs(slcr);
 
@@ -108,6 +112,10 @@ impl ClockSource for ArmPll {
     fn pll_locked(pll_status: &mut crate::slcr::PllStatus) -> bool {
         pll_status.read().arm_pll_lock()
     }
+
+    fn name() -> &'static str {
+        &"ARM_PLL"
+    }
 }
 
 /// DDR PLL: Recommended clock for the DDR DRAM controller and AXI_HP interfaces
@@ -130,6 +138,10 @@ impl ClockSource for DdrPll {
     fn pll_locked(pll_status: &mut crate::slcr::PllStatus) -> bool {
         pll_status.read().ddr_pll_lock()
     }
+
+    fn name() -> &'static str {
+        &"DDR_PLL"
+    }
 }
 
 /// I/O PLL: Recommended clock for I/O peripherals
@@ -153,4 +165,8 @@ impl ClockSource for IoPll {
     fn pll_locked(pll_status: &mut crate::slcr::PllStatus) -> bool {
         pll_status.read().io_pll_lock()
     }
+
+    fn name() -> &'static str {
+        &"IO_PLL"
+    }
 }

libboard_zynq/src/ddr/mod.rs

@@ -1,4 +1,5 @@
 use libregister::{RegisterR, RegisterW, RegisterRW};
+use log::{error, info};
 use crate::{print, println};
 use super::slcr::{self, DdriobVrefSel};
 use super::clocks::{Clocks, source::{DdrPll, ClockSource}};
@@ -38,11 +39,9 @@ impl DdrRam {
         DdrPll::setup(2 * DDR_FREQ);
 
         let clocks = Clocks::get();
-        println!("Clocks: {:?}", clocks);
-
         let ddr3x_clk_divisor = 2;
         let ddr2x_clk_divisor = 3;
-        println!("DDR 3x/2x clocks: {}/{}", clocks.ddr / u32::from(ddr3x_clk_divisor), clocks.ddr / u32::from(ddr2x_clk_divisor));
+        info!("DDR 3x/2x clocks: {}/{}", clocks.ddr / u32::from(ddr3x_clk_divisor), clocks.ddr / u32::from(ddr2x_clk_divisor));
 
         slcr::RegisterBlock::unlocked(|slcr| {
             slcr.ddr_clk_ctrl.write(
@@ -63,7 +62,7 @@ impl DdrRam {
             .max(1).min(63) as u8;
         let divisor1 = ((DCI_FREQ - 1 + clocks.ddr) / DCI_FREQ / u32::from(divisor0))
             .max(1).min(63) as u8;
-        println!("DDR DCI clock: {} Hz", clocks.ddr / u32::from(divisor0) / u32::from(divisor1));
+        info!("DDR DCI clock: {} Hz", clocks.ddr / u32::from(divisor0) / u32::from(divisor1));
 
         slcr::RegisterBlock::unlocked(|slcr| {
             // Step 1.
@@ -226,7 +225,7 @@ impl DdrRam {
         let patterns: &'static [u32] = &[0xffff_ffff, 0x5555_5555, 0xaaaa_aaaa, 0];
         let mut expected = None;
         for (i, pattern) in patterns.iter().enumerate() {
-            println!("memtest phase {} (status: {:?})", i, self.status());
+            info!("memtest phase {} (status: {:?})", i, self.status());
 
             for megabyte in 0..=(slice.len() / (1024 * 1024)) {
                 let start = megabyte * 1024 * 1024 / 4;
@@ -235,7 +234,7 @@ impl DdrRam {
                     expected.map(|expected| {
                         let read: u32 = *b;
                         if read != expected {
-                            println!("{:08X}: expected {:08X}, read {:08X}", b as *mut _ as usize, expected, read);
+                            error!("{:08X}: expected {:08X}, read {:08X}", b as *mut _ as usize, expected, read);
                         }
                     });
                     *b = *pattern;

libboard_zynq/src/eth/mod.rs

@@ -1,6 +1,6 @@
 use core::ops::{Deref, DerefMut};
+use log::{error, info, warn};
 use libregister::*;
-use crate::println;
 use super::slcr;
 use super::clocks::Clocks;
 
@@ -389,7 +389,7 @@ impl<'r, 'rx, 'tx: 'a, 'a> smoltcp::phy::Device<'a> for &mut Eth<'r, rx::DescLis
                 None
             }
             Err(e) => {
-                println!("eth recv error: {:?}", e);
+                error!("eth recv error: {:?}", e);
                 None
             }
         }
@@ -555,7 +555,7 @@ impl<'r> EthInner<'r> {
         if self.link != link {
             match &link {
                 Some(link) => {
-                    println!("eth: got {:?}", link);
+                    info!("eth: got {:?}", link);
 
                     use phy::LinkSpeed::*;
                     let txclock = match link.speed {
@@ -573,7 +573,7 @@ impl<'r> EthInner<'r> {
                     );
                 }
                 None => {
-                    println!("eth: link lost");
+                    warn!("eth: link lost");
                     phy.modify_control(self, |control|
                                        control.set_autoneg_enable(true)
                                        .set_restart_autoneg(true)

libboard_zynq/src/flash/mod.rs

@@ -1,8 +1,9 @@
 //! Quad-SPI Flash Controller
 
-use crate::{print, println};
 use core::marker::PhantomData;
+use log::{error, info, warn};
 use libregister::{RegisterR, RegisterW, RegisterRW};
+use crate::{print, println};
 use super::slcr;
 use super::clocks::source::{IoPll, ClockSource};
 
@@ -422,17 +423,17 @@ impl Flash<Manual> {
         let sr1 = self.wait_while_sr1_zeroed();
 
         if sr1.e_err() {
-            println!("E_ERR");
+            error!("E_ERR");
         } else if sr1.p_err() {
-            println!("P_ERR");
+            error!("P_ERR");
         } else if sr1.wip() {
-            print!("Erase in progress");
+            info!("Erase in progress");
             while self.read_reg::<SR1>().wip() {
                 print!(".");
             }
             println!("");
         } else {
-            println!("erased? sr1={:02X}", sr1.inner);
+            warn!("erased? sr1={:02X}", sr1.inner);
         }
     }
 
@@ -448,17 +449,17 @@ impl Flash<Manual> {
         let sr1 = self.read_reg::<SR1>();
 
         if sr1.e_err() {
-            println!("E_ERR");
+            error!("E_ERR");
         } else if sr1.p_err() {
-            println!("P_ERR");
+            error!("P_ERR");
         } else if sr1.wip() {
-            println!("Program in progress");
+            info!("Program in progress");
             while self.read_reg::<SR1>().wip() {
                 print!(".");
             }
             println!("");
         } else {
-            println!("programmed? sr1={:02X}", sr1.inner);
+            warn!("programmed? sr1={:02X}", sr1.inner);
         }
     }