add detailed color-coded logging

Cargo.lock

@@ -112,6 +112,15 @@ dependencies = [
  "windows-targets 0.52.0",
 ]
 
+[[package]]
+name = "colour"
+version = "0.7.0"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "0f58a501d883cdb7f1a780407eefba005458b8fdf7c09213ea0104879bf87aa9"
+dependencies = [
+ "crossterm",
+]
+
 [[package]]
 name = "core-foundation"
 version = "0.9.4"
@@ -128,6 +137,31 @@ version = "0.8.6"
 source = "registry+https://github.com/rust-lang/crates.io-index"
 checksum = "06ea2b9bc92be3c2baa9334a323ebca2d6f074ff852cd1d7b11064035cd3868f"
 
+[[package]]
+name = "crossterm"
+version = "0.26.1"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "a84cda67535339806297f1b331d6dd6320470d2a0fe65381e79ee9e156dd3d13"
+dependencies = [
+ "bitflags",
+ "crossterm_winapi",
+ "libc",
+ "mio",
+ "parking_lot",
+ "signal-hook",
+ "signal-hook-mio",
+ "winapi",
+]
+
+[[package]]
+name = "crossterm_winapi"
+version = "0.9.1"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "acdd7c62a3665c7f6830a51635d9ac9b23ed385797f70a83bb8bafe9c572ab2b"
+dependencies = [
+ "winapi",
+]
+
 [[package]]
 name = "csv"
 version = "1.3.0"
@@ -403,6 +437,7 @@ source = "registry+https://github.com/rust-lang/crates.io-index"
 checksum = "8f3d0b296e374a4e6f3c7b0a1f5a51d748a0d34c85e7dc48fc3fa9a87657fe09"
 dependencies = [
  "libc",
+ "log",
  "wasi",
  "windows-sys 0.48.0",
 ]
@@ -447,6 +482,29 @@ version = "0.1.5"
 source = "registry+https://github.com/rust-lang/crates.io-index"
 checksum = "ff011a302c396a5197692431fc1948019154afc178baf7d8e37367442a4601cf"
 
+[[package]]
+name = "parking_lot"
+version = "0.12.1"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "3742b2c103b9f06bc9fff0a37ff4912935851bee6d36f3c02bcc755bcfec228f"
+dependencies = [
+ "lock_api",
+ "parking_lot_core",
+]
+
+[[package]]
+name = "parking_lot_core"
+version = "0.9.9"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "4c42a9226546d68acdd9c0a280d17ce19bfe27a46bf68784e4066115788d008e"
+dependencies = [
+ "cfg-if",
+ "libc",
+ "redox_syscall",
+ "smallvec",
+ "windows-targets 0.48.5",
+]
+
 [[package]]
 name = "pin-project-lite"
 version = "0.2.13"
@@ -477,6 +535,15 @@ dependencies = [
  "proc-macro2",
 ]
 
+[[package]]
+name = "redox_syscall"
+version = "0.4.1"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "4722d768eff46b75989dd134e5c353f0d6296e5aaa3132e776cbdb56be7731aa"
+dependencies = [
+ "bitflags",
+]
+
 [[package]]
 name = "ring"
 version = "0.17.7"
@@ -641,6 +708,36 @@ dependencies = [
  "serde",
 ]
 
+[[package]]
+name = "signal-hook"
+version = "0.3.17"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "8621587d4798caf8eb44879d42e56b9a93ea5dcd315a6487c357130095b62801"
+dependencies = [
+ "libc",
+ "signal-hook-registry",
+]
+
+[[package]]
+name = "signal-hook-mio"
+version = "0.2.3"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "29ad2e15f37ec9a6cc544097b78a1ec90001e9f71b81338ca39f430adaca99af"
+dependencies = [
+ "libc",
+ "mio",
+ "signal-hook",
+]
+
+[[package]]
+name = "signal-hook-registry"
+version = "1.4.1"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "d8229b473baa5980ac72ef434c4415e70c4b5e71b423043adb4ba059f89c99a1"
+dependencies = [
+ "libc",
+]
+
 [[package]]
 name = "slab"
 version = "0.4.9"
@@ -650,6 +747,12 @@ dependencies = [
  "autocfg",
 ]
 
+[[package]]
+name = "smallvec"
+version = "1.13.1"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "e6ecd384b10a64542d77071bd64bd7b231f4ed5940fba55e98c3de13824cf3d7"
+
 [[package]]
 name = "socket2"
 version = "0.5.5"
@@ -666,6 +769,7 @@ version = "0.1.0"
 dependencies = [
  "boolinator",
  "chrono",
+ "colour",
  "csv",
  "futures",
  "itertools",
@@ -868,6 +972,28 @@ version = "0.2.91"
 source = "registry+https://github.com/rust-lang/crates.io-index"
 checksum = "4f186bd2dcf04330886ce82d6f33dd75a7bfcf69ecf5763b89fcde53b6ac9838"
 
+[[package]]
+name = "winapi"
+version = "0.3.9"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "5c839a674fcd7a98952e593242ea400abe93992746761e38641405d28b00f419"
+dependencies = [
+ "winapi-i686-pc-windows-gnu",
+ "winapi-x86_64-pc-windows-gnu",
+]
+
+[[package]]
+name = "winapi-i686-pc-windows-gnu"
+version = "0.4.0"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "ac3b87c63620426dd9b991e5ce0329eff545bccbbb34f3be09ff6fb6ab51b7b6"
+
+[[package]]
+name = "winapi-x86_64-pc-windows-gnu"
+version = "0.4.0"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "712e227841d057c1ee1cd2fb22fa7e5a5461ae8e48fa2ca79ec42cfc1931183f"
+
 [[package]]
 name = "windows-core"
 version = "0.52.0"

Cargo.toml

@@ -19,3 +19,4 @@ tap = "1.0.1"
 lazy_static = "1.4.0"
 toml = "0.8.10"
 futures = "0.3.30"
+colour = "0.7.0"

src/main.rs

@@ -1,6 +1,7 @@
 use std::time::Duration;
 use std::collections::{HashMap, HashSet};
 
+use colour::{green_ln, magenta_ln, yellow_ln};
 use lazy_static::*;
 use rumqttc::{AsyncClient, EventLoop, MqttOptions, QoS};
 use state::{Announcer, Listener, State};
@@ -32,8 +33,10 @@ lazy_static! {
 
 #[tokio::main]
 async fn main() {
+	magenta_ln!("===== spacermake =====");
+	print_config();
 	let (client, event_loop) = create_client().await;
-
+	magenta_ln!("start");
 	let listener = State::new(Listener, client);
 	let announcer = listener.duplicate_as(Announcer);
 
@@ -41,6 +44,15 @@ async fn main() {
 	listener.run(event_loop).await;
 }
 
+fn print_config() {
+	let slaves_by_master: &HashMap<_, _> = &SLAVES_BY_MASTER;
+	let slave_properties: &HashMap<_, _> = &SLAVE_PROPERTIES;
+	let machine_ids: &HashMap<_, _> = &MACHINE_IDS;
+	yellow_ln!("{slaves_by_master:#?}");
+	green_ln!("{slave_properties:#?}");
+	yellow_ln!("{machine_ids:#?}");
+}
+
 async fn create_client() -> (AsyncClient, EventLoop) {
 	let mut mqttoptions = MqttOptions::new("spacermake", "mqtt.makerspace-bocholt.local", 1883);
 	mqttoptions.set_keep_alive(Duration::from_secs(5));

src/state.rs

@@ -2,6 +2,7 @@ use std::time::Instant;
 use std::sync::Arc;
 use std::collections::{HashMap, VecDeque};
 
+use colour::dark_grey_ln;
 use rumqttc::{AsyncClient, QoS};
 use tokio::sync::RwLock;
 
@@ -43,7 +44,8 @@ impl<Kind> State<Kind> {
     }
 
     //probably doesn't belong here, dunno where else to put it
-    async fn update_power_state(&self, machine: &str, new_state: bool) {
+    async fn set_power_state(&self, machine: &str, new_state: bool) {
+        dark_grey_ln!("set power state - {machine} {new_state}");
         let is_tasmota = SLAVE_PROPERTIES[machine][index::IS_TASMOTA];
         let topic =
             if is_tasmota {
@@ -60,6 +62,7 @@ impl<Kind> State<Kind> {
                 if new_state { b"on".as_slice() } else { b"off".as_slice() }
             };
 
+        dark_grey_ln!("publishing\n  topic: {topic}\n  payload: {payload:?}");
         self.client
             .read()
             .await

src/state/announcer.rs

@@ -1,5 +1,6 @@
 use std::time::{Duration, Instant};
 
+use colour::{blue_ln, red_ln};
 use futures::join;
 use futures::future::join_all;
 use rumqttc::QoS;
@@ -32,8 +33,10 @@ impl State<Announcer> {
                     return None;
                 }
 
+                blue_ln!("updating display of {machine}");
+
                 let Some(id) = MACHINE_IDS.get(machine) else {
-                    println!("error: no ID found for {machine}");
+                    red_ln!("error: no ID found for {machine}");
                     return None;
                 };
 
@@ -65,8 +68,9 @@ impl State<Announcer> {
             if time > &now {
                 break;
             }
+            blue_ln!("performing scheduled shutdown of {machine}");
 
-            self.update_power_state(machine, false).await;
+            self.set_power_state(machine, false).await;
             schedule.pop_front();
         }
     }

src/state/listener.rs

@@ -2,6 +2,7 @@ use std::ops::Sub;
 use std::time::{Duration, Instant};
 
 use boolinator::Boolinator;
+use colour::{cyan_ln, dark_grey_ln, red_ln};
 use rumqttc::EventLoop;
 use rumqttc::Event::Incoming;
 use rumqttc::Packet::Publish;
@@ -21,20 +22,17 @@ impl State<Listener> {
                 .expect("notification error")
                 else { continue };
 
+            dark_grey_ln!("publish received");
             self.on_publish(publish).await;
         }
     }
 
     async fn on_publish(&mut self, publish: rumqttc::Publish) {
-        //pretty ugly, cant figure out a clean way to do this
+        let Ok(payload) = String::from_utf8(publish.payload.clone().into()) else {
-        let Ok(payload) = String::from_utf8(publish.payload.clone().into())
+            red_ln!("publish with non-utf8 payload received - {:?}", publish.payload);
-            else {
+            return;
-                log_debug(&publish.topic, &format!("{:?}", &publish.payload), Err("non-utf8 payload"))
+        };
-                    .expect("debug log failed");
+        dark_grey_ln!("payload: {payload}");
-
-                return;
-            };
-        //end of ugly
 
         let result = self.handle_payload(&publish.topic, &payload).await;
 
@@ -73,13 +71,14 @@ impl State<Listener> {
             _ => return Ok(()) //ignore other statuses
         }
 
-        println!("info: {user} {status} {machine}");
+        cyan_ln!("{user} {status} {machine}");
 
         Ok(())
     }
 
     #[allow(clippy::ptr_arg)] //false positive
     async fn try_book(&mut self, machine: &String, user: &String) -> Result<(), &'static str> {
+        dark_grey_ln!("booking {machine}");
         let mut bookings = self.bookings.write().await;
         if bookings.contains_key(machine) {
             return Err("machine got double-booked");
@@ -90,6 +89,7 @@ impl State<Listener> {
     }
 
     async fn try_release(&mut self, machine: &String) -> Result<(), &'static str> {
+        dark_grey_ln!("releasing {machine}");
         let mut booking = self
             .bookings
             .write()
@@ -126,12 +126,13 @@ impl State<Listener> {
 
         self.update_slaves(machine, true, false, power).await?;
 
-        println!("info: {machine} got turned {power_string}");
+        cyan_ln!("info: {machine} got turned {power_string}");
 
         Ok(())
     }
 
     pub async fn update_slaves(&mut self, master: &String, short_slaves: bool, long_slaves: bool, power: bool) -> Result<(), &'static str> {
+        dark_grey_ln!("updating slaves...");
         let slaves_used_by_others = self
             .bookings
             .read()
@@ -151,12 +152,13 @@ impl State<Listener> {
 
         for slave in slaves_to_update {
             if !power && SLAVE_PROPERTIES[&slave][index::NEEDS_TRAILING_TIME] {
+                dark_grey_ln!("scheduling delayed shutdown for {}", slave);
                 let shutdown_timestamp = Instant::now() + Duration::from_secs(30);
                 self.scheduled_shutdowns.write().await.push_back((shutdown_timestamp, slave));
                 continue;
             }
 
-            self.update_power_state(&slave, power).await;
+            self.set_power_state(&slave, power).await;
         }
 
         Ok(())

src/utils/logs.rs

@@ -3,12 +3,13 @@ use std::io::{self, Write};
 use std::fs::File;
 
 use chrono::Local;
+use colour::red_ln;
 use serde::Serialize;
 use tap::Pipe;
 
 use crate::utils::booking::Booking;
 
-#[derive(Serialize)]
+#[derive(Debug, Serialize)]
 struct Record<'s> {
     machine: &'s str,
     date: String,
@@ -34,19 +35,19 @@ pub fn machinelog(machine: &str, booking: &Booking) -> io::Result<()> {
         .append(true)
         .open("/root/machinelog.csv")?
         .pipe(csv::Writer::from_writer)
-        .serialize(record)
+        .serialize(&record)
-        .map_err(|err| {
+        .map_err(|error| {
-            println!("serialization error: {}", err);
+            red_ln!("error while serializing: {error}\n{record:#?}");
             io::ErrorKind::Other.into()
         })
 }
 
 pub fn log_debug(topic: &str, payload: &str, result: Result<(), &str>) -> io::Result<()> {
     if let Err(error) = result {
-        println!("error: {error}");
+        red_ln!("error: {error}");
-        println!("	topic: {topic}");
+        red_ln!("	topic: {topic}");
-        println!("	payload: {payload}");
+        red_ln!("	payload: {payload}");
-        println!()
+        red_ln!()
     }
 
     let time = Local::now().to_string();