log: inform itm issue

src/flash.rs

@@ -3,7 +3,6 @@ use embedded_hal::{
     blocking::spi::Transfer,
     blocking::delay::DelayUs,
 };
-use log::info;
 
 #[derive(Debug)]
 pub enum FPGAFlashError {
@@ -85,10 +84,8 @@ pub fn flash_ice40_fpga<SPI: Transfer<u8>,
         _ => return Err(FPGAFlashError::ResetStatusError),
     };
 
-    info!("Configuration successful!");
     // Send at least another 49 clock cycles to activate IO pins (choosing same 13 bytes)
     spi.transfer(&mut dummy_13_bytes).map_err(|_| FPGAFlashError::SPICommunicationError)?;
-    info!("User I/O pins activated.");
     Ok(())
 
 }

src/logger.rs

@@ -0,0 +1,78 @@
+// Enables ITM
+pub unsafe fn enable_itm(
+    dbgmcu: &stm32h7xx_hal::stm32::DBGMCU,
+    dcb: &mut cortex_m::peripheral::DCB,
+    itm: &mut cortex_m::peripheral::ITM
+) {
+    // ARMv7-M DEMCR: Set TRCENA. Enables DWT and ITM units
+    //unsafe { *(0xE000_EDFC as *mut u32) |= 1 << 24 };
+    dcb.enable_trace();
+
+    // Ensure debug blocks are clocked before interacting with them
+    dbgmcu.cr.modify(|_, w| {
+        w.d1dbgcken()
+            .set_bit()
+            .d3dbgcken()
+            .set_bit()
+            .traceclken()
+            .set_bit()
+            .dbgsleep_d1()
+            .set_bit()
+    });
+
+    // SWO: Unlock
+    *(0x5c00_3fb0 as *mut u32) = 0xC5ACCE55;
+    // SWTF: Unlock
+    *(0x5c00_4fb0 as *mut u32) = 0xC5ACCE55;
+
+    // SWO CODR Register: Set SWO speed
+    *(0x5c00_3010 as *mut _) = 200;
+
+    // SWO SPPR Register:
+    // 1 = Manchester
+    // 2 = NRZ
+    *(0x5c00_30f0 as *mut _) = 2;
+
+    // SWTF Trace Funnel: Enable for CM7
+    *(0x5c00_4000 as *mut u32) |= 1;
+
+    // ITM: Unlock
+    itm.lar.write(0xC5ACCE55);
+    // ITM Trace Enable Register: Enable lower 8 stimulus ports
+    itm.ter[0].write(1);
+    // ITM Trace Control Register: Enable ITM
+    itm.tcr.write(
+        (0b000001 << 16) | // TraceBusID
+        (1 << 3) | // enable SWO output
+        (1 << 0), // enable the ITM
+    );
+}
+
+use panic_itm as _;
+
+use lazy_static::lazy_static;
+use log::LevelFilter;
+
+pub use cortex_m_log::log::Logger;
+
+use cortex_m_log::{
+    destination::Itm as ItmDest,
+    printer::itm::InterruptSync,
+    modes::InterruptFree,
+    printer::itm::ItmSync
+};
+
+lazy_static! {
+    static ref LOGGER: Logger<ItmSync<InterruptFree>> = Logger {
+        level: LevelFilter::Trace,
+        inner: unsafe {
+            InterruptSync::new(
+                ItmDest::new(cortex_m::Peripherals::steal().ITM)
+            )
+        },
+    };
+}
+
+pub fn init() {
+    cortex_m_log::log::init(&LOGGER).unwrap();
+}

src/main.rs

@@ -37,7 +37,6 @@ use crate::mqtt_mux::MqttMux;
 pub mod urukul;
 use crate::urukul::Urukul;
 
-#[path = "../examples/util/logger.rs"]
 mod logger;
 
 static mut NET_STORE: NetStorage = NetStorage {
@@ -74,15 +73,15 @@ fn main() -> ! {
 	let mut cp = cortex_m::Peripherals::take().unwrap();
 	let dp = pac::Peripherals::take().unwrap();
 
-    cp.DWT.enable_cycle_counter();
+	unsafe {
+		logger::enable_itm(&dp.DBGMCU, &mut cp.DCB, &mut cp.ITM);
+	}
+	logger::init();
 
     // Enable SRAM3 for the descriptor ring.
     dp.RCC.ahb2enr.modify(|_, w| w.sram3en().set_bit());
-    // Reset RCC clock
+    // // Reset RCC clock
-	dp.RCC.rsr.write(|w| w.rmvf().set_bit());
+	// dp.RCC.rsr.write(|w| w.rmvf().set_bit());
-	
-	cp.SCB.invalidate_icache();
-    cp.SCB.enable_icache();
 
 	let pwr = dp.PWR.constrain();
 	let vos = pwr.freeze();
@@ -96,12 +95,12 @@ fn main() -> ! {
 		.pll1_r_ck(400.mhz())
 		.freeze(vos, &dp.SYSCFG);
 	
-	// unsafe {
+    let delay = cp.SYST.delay(ccdr.clocks);
-	// 	logger::enable_itm(&dp.DBGMCU, &mut cp.DCB, &mut cp.ITM);
-	// }
-	// logger::init();
     
-	let mut delay = cp.SYST.delay(ccdr.clocks);
+    cp.SCB.invalidate_icache();
+    cp.SCB.enable_icache();
+
+    cp.DWT.enable_cycle_counter();
 
 	let gpioa = dp.GPIOA.split(ccdr.peripheral.GPIOA);
 	let gpiob = dp.GPIOB.split(ccdr.peripheral.GPIOB);
@@ -111,11 +110,12 @@ fn main() -> ! {
 	let gpiof = dp.GPIOF.split(ccdr.peripheral.GPIOF);
     let gpiog = dp.GPIOG.split(ccdr.peripheral.GPIOG);
 
-    gpiob.pb3.into_alternate_af0().set_speed(Speed::VeryHigh);
+    // Note: ITM doesn't work beyond this, due to a pin conflict between:
+    // - FPGA_SPI: SCK  (af5)
+    // - ST_LINK SWO    (af0)
+    // Both demands PB3
+	trace!("Flashing configuration bitstream to iCE40 HX8K on Humpback.");
 
-	// trace!("Flashing configuration bitstream to iCE40 HX8K on Humpback.");
-	// delay.delay_ms(1000_u16);
-/*
 	// Using SPI_1 alternate functions (af5)
 	let fpga_sck = gpiob.pb3.into_alternate_af5();
 	let fpga_sdo = gpiob.pb4.into_alternate_af5();
@@ -138,7 +138,7 @@ fn main() -> ! {
 	);
 
 	flash_ice40_fpga(fpga_cfg_spi, fpga_ss, fpga_creset, fpga_cdone, delay).unwrap();
-*/
+
     // Configure ethernet IO
     {
         let _rmii_refclk = gpioa.pa1.into_alternate_af11().set_speed(Speed::VeryHigh);
@@ -207,7 +207,7 @@ fn main() -> ! {
 	let spi = dp.SPI6.spi(
 		(sclk, miso, mosi),
 		spi::MODE_0,
-		2.mhz(),
+		10.mhz(),
 		ccdr.peripheral.SPI6,
 		&ccdr.clocks,
 	);
@@ -219,13 +219,8 @@ fn main() -> ! {
         parts.spi1, parts.spi2, parts.spi3, parts.spi4, parts.spi5, parts.spi6, parts.spi7
     );
 
-	unsafe {
-		logger::enable_itm(&dp.DBGMCU, &mut cp.DCB, &mut cp.ITM);
-	}
-	logger::init();
-
 	urukul.reset().unwrap();
-	info!("Test value: {}", urukul.test().unwrap());
+	// info!("Test value: {}", urukul.test().unwrap());
 
 	let mut mqtt_mux = MqttMux::new(urukul);
 
@@ -248,7 +243,7 @@ fn main() -> ! {
     //              Probably fixed in latest smoltcp commit
     let mut client = MqttClient::<consts::U256, _>::new(
         IpAddr::V4(Ipv4Addr::new(192, 168, 1, 125)),
-        "Nucleo",
+        "Urukul",
         tcp_stack,
     )
     .unwrap();
@@ -274,22 +269,25 @@ fn main() -> ! {
         // Process MQTT messages about Urukul/Control
         let connection = client
             .poll(|_client, topic, message, _properties| {
-                info!("On {:?}, received: {:?}", topic, message);
+                // info!("On {:?}, received: {:?}", topic, message);
                 // Why is topic a string while message is a slice?
-                mqtt_mux.process_mqtt(topic, message);
+                mqtt_mux.process_mqtt(topic, message).is_ok();
             }).is_ok();
         
         if connection && !has_subscribed && tick {
             match client.subscribe("Urukul/Control/#", &[]) {
                 Ok(()) => has_subscribed = true,
-                Err(minimq::Error::NotReady) => warn!("Minimq is not ready"),
+                Err(minimq::Error::NotReady) => {},
-                e => warn!("{:?}", e),
+                _e => {},
             };
         }
 
         if connection && tick && (time % 3000) == 0 {
-            info!("Feedback from print publish: {:?}", client
+            client.publish("Urukul/Channel1/Switch", mqtt_mux
-                .publish("Channel1/Switch", mqtt_mux.get_switch_status_message(1).unwrap().as_bytes(), QoS::AtMostOnce, &[]));
+                .get_switch_status_message(1)
+                .unwrap()
+                .as_bytes(), QoS::AtMostOnce, &[])
+                .unwrap();
         }
 
         // Reset tick flag