added verbose logging feature and tests

This commit is contained in:
2025-10-07 19:01:37 -05:00
parent 7d2c10fe11
commit 40ece06d2d
7 changed files with 417 additions and 82 deletions
+1
View File
@@ -135,3 +135,4 @@ The original includes a dummy adjustment method for testing without actual displ
- Unit tests for color temperature conversion - Unit tests for color temperature conversion
- Integration tests with dummy/mock adjustment methods - Integration tests with dummy/mock adjustment methods
- Always generate a coverage report at the end of a task and write tests for any uncovered lines or branches that were not previously ignored or skipped. - Always generate a coverage report at the end of a task and write tests for any uncovered lines or branches that were not previously ignored or skipped.
- Always add logging using the internal logging function where appropriate.
+2
View File
@@ -19,6 +19,8 @@ lazy_static = "1.5"
dialoguer = "0.11" dialoguer = "0.11"
signal-hook = "0.3" signal-hook = "0.3"
rust-ini = "0.21" rust-ini = "0.21"
log = "0.4"
env_logger = "0.11"
[dev-dependencies] [dev-dependencies]
libc = "0.2" libc = "0.2"
+23
View File
@@ -3,6 +3,7 @@
use crate::types::*; use crate::types::*;
use ini::Ini; use ini::Ini;
use log::{debug, info, trace};
use std::path::PathBuf; use std::path::PathBuf;
/// Configuration loaded from INI file /// Configuration loaded from INI file
@@ -35,9 +36,12 @@ pub struct RedshiftConfig {
impl RedshiftConfig { impl RedshiftConfig {
/// Find and load the INI config file from standard locations /// Find and load the INI config file from standard locations
pub fn load() -> Result<Self, String> { pub fn load() -> Result<Self, String> {
debug!("Searching for INI configuration file");
if let Some(path) = Self::find_config_file() { if let Some(path) = Self::find_config_file() {
info!("Found INI config file: {}", path.display());
Self::load_from_file(&path) Self::load_from_file(&path)
} else { } else {
debug!("No INI configuration file found, using defaults");
Ok(Self::default()) Ok(Self::default())
} }
} }
@@ -46,7 +50,9 @@ impl RedshiftConfig {
pub fn find_config_file() -> Option<PathBuf> { pub fn find_config_file() -> Option<PathBuf> {
let paths = Self::get_config_search_paths(); let paths = Self::get_config_search_paths();
trace!("Searching for INI config in {} locations", paths.len());
for path in paths { for path in paths {
trace!("Checking: {}", path.display());
if path.exists() { if path.exists() {
return Some(path); return Some(path);
} }
@@ -84,6 +90,7 @@ impl RedshiftConfig {
/// Load config from a specific file /// Load config from a specific file
pub fn load_from_file(path: &PathBuf) -> Result<Self, String> { pub fn load_from_file(path: &PathBuf) -> Result<Self, String> {
debug!("Loading INI config from: {}", path.display());
let ini = Ini::load_from_file(path) let ini = Ini::load_from_file(path)
.map_err(|e| format!("Failed to load INI file: {}", e))?; .map_err(|e| format!("Failed to load INI file: {}", e))?;
@@ -93,9 +100,15 @@ impl RedshiftConfig {
if let Some(section) = ini.section(Some("redshift")) { if let Some(section) = ini.section(Some("redshift")) {
if let Some(val) = section.get("temp-day") { if let Some(val) = section.get("temp-day") {
config.temp_day = val.parse().ok(); config.temp_day = val.parse().ok();
if let Some(temp) = config.temp_day {
debug!("Loaded temp-day from INI: {}K", temp);
}
} }
if let Some(val) = section.get("temp-night") { if let Some(val) = section.get("temp-night") {
config.temp_night = val.parse().ok(); config.temp_night = val.parse().ok();
if let Some(temp) = config.temp_night {
debug!("Loaded temp-night from INI: {}K", temp);
}
} }
if let Some(val) = section.get("fade") { if let Some(val) = section.get("fade") {
config.fade = match val { config.fade = match val {
@@ -177,18 +190,28 @@ impl RedshiftConfig {
if let Some(val) = section.get("lon") { if let Some(val) = section.get("lon") {
config.manual_lon = val.parse().ok(); config.manual_lon = val.parse().ok();
} }
if let (Some(lat), Some(lon)) = (config.manual_lat, config.manual_lon) {
debug!("Loaded manual location from INI: {:.4}, {:.4}", lat, lon);
}
} }
/* Parse [randr] section for gamma method settings */ /* Parse [randr] section for gamma method settings */
if let Some(section) = ini.section(Some("randr")) { if let Some(section) = ini.section(Some("randr")) {
if let Some(val) = section.get("screen") { if let Some(val) = section.get("screen") {
config.randr_screen = val.parse().ok(); config.randr_screen = val.parse().ok();
if let Some(screen) = config.randr_screen {
debug!("Loaded RandR screen from INI: {}", screen);
}
} }
if let Some(val) = section.get("crtc") { if let Some(val) = section.get("crtc") {
config.randr_crtc = val.parse().ok(); config.randr_crtc = val.parse().ok();
if let Some(crtc) = config.randr_crtc {
debug!("Loaded RandR CRTC from INI: {}", crtc);
}
} }
} }
trace!("INI configuration loaded successfully");
Ok(config) Ok(config)
} }
+37 -5
View File
@@ -4,6 +4,7 @@
use crate::colorramp::colorramp_fill; use crate::colorramp::colorramp_fill;
use crate::gamma::GammaMethod; use crate::gamma::GammaMethod;
use crate::types::ColorSetting; use crate::types::ColorSetting;
use log::{debug, info, trace, warn};
use std::fmt; use std::fmt;
use x11rb::connection::Connection; use x11rb::connection::Connection;
use x11rb::protocol::randr; use x11rb::protocol::randr;
@@ -72,6 +73,13 @@ impl RandrGammaMethod {
let conn = self.conn.as_ref().ok_or("Not connected to X server")?; let conn = self.conn.as_ref().ok_or("Not connected to X server")?;
let ramp_size = crtc_state.ramp_size as usize; let ramp_size = crtc_state.ramp_size as usize;
trace!(
"Setting temperature for CRTC: temp={}K, brightness={:.2}, gamma=[{:.2}, {:.2}, {:.2}], preserve={}",
setting.temperature, setting.brightness,
setting.gamma[0], setting.gamma[1], setting.gamma[2],
preserve
);
/* Create new gamma ramps */ /* Create new gamma ramps */
let mut gamma_r = vec![0u16; ramp_size]; let mut gamma_r = vec![0u16; ramp_size];
let mut gamma_g = vec![0u16; ramp_size]; let mut gamma_g = vec![0u16; ramp_size];
@@ -79,11 +87,13 @@ impl RandrGammaMethod {
if preserve { if preserve {
/* Initialize from saved state */ /* Initialize from saved state */
debug!("Preserving original gamma ramps");
gamma_r.copy_from_slice(&crtc_state.saved_ramps[0..ramp_size]); gamma_r.copy_from_slice(&crtc_state.saved_ramps[0..ramp_size]);
gamma_g.copy_from_slice(&crtc_state.saved_ramps[ramp_size..2 * ramp_size]); gamma_g.copy_from_slice(&crtc_state.saved_ramps[ramp_size..2 * ramp_size]);
gamma_b.copy_from_slice(&crtc_state.saved_ramps[2 * ramp_size..3 * ramp_size]); gamma_b.copy_from_slice(&crtc_state.saved_ramps[2 * ramp_size..3 * ramp_size]);
} else { } else {
/* Initialize to linear (pure state) */ /* Initialize to linear (pure state) */
trace!("Starting with linear gamma ramps");
for i in 0..ramp_size { for i in 0..ramp_size {
let value = ((i as f64 / ramp_size as f64) * 65536.0) as u16; let value = ((i as f64 / ramp_size as f64) * 65536.0) as u16;
gamma_r[i] = value; gamma_r[i] = value;
@@ -95,6 +105,14 @@ impl RandrGammaMethod {
/* Apply color temperature adjustment */ /* Apply color temperature adjustment */
colorramp_fill(&mut gamma_r, &mut gamma_g, &mut gamma_b, setting); colorramp_fill(&mut gamma_r, &mut gamma_g, &mut gamma_b, setting);
trace!("Gamma ramp sample (first 5 values): R=[{}, {}, {}, {}, {}]",
gamma_r.get(0).unwrap_or(&0),
gamma_r.get(1).unwrap_or(&0),
gamma_r.get(2).unwrap_or(&0),
gamma_r.get(3).unwrap_or(&0),
gamma_r.get(4).unwrap_or(&0),
);
/* Set gamma ramps */ /* Set gamma ramps */
randr::set_crtc_gamma( randr::set_crtc_gamma(
conn, conn,
@@ -119,11 +137,14 @@ impl Default for RandrGammaMethod {
impl GammaMethod for RandrGammaMethod { impl GammaMethod for RandrGammaMethod {
fn init(&mut self) -> Result<(), String> { fn init(&mut self) -> Result<(), String> {
debug!("Initializing RandR gamma method");
/* Open X server connection */ /* Open X server connection */
let (conn, preferred_screen) = RustConnection::connect(None) let (conn, preferred_screen) = RustConnection::connect(None)
.map_err(|e| format!("Failed to connect to X server: {}", e))?; .map_err(|e| format!("Failed to connect to X server: {}", e))?;
self.preferred_screen = preferred_screen; self.preferred_screen = preferred_screen;
info!("Connected to X server (screen {})", preferred_screen);
/* Query RandR version */ /* Query RandR version */
let ver_reply = randr::query_version(&conn, RANDR_VERSION_MAJOR, RANDR_VERSION_MINOR) let ver_reply = randr::query_version(&conn, RANDR_VERSION_MAJOR, RANDR_VERSION_MINOR)
@@ -140,6 +161,8 @@ impl GammaMethod for RandrGammaMethod {
)); ));
} }
debug!("RandR version: {}.{}", ver_reply.major_version, ver_reply.minor_version);
self.conn = Some(conn); self.conn = Some(conn);
Ok(()) Ok(())
} }
@@ -148,6 +171,8 @@ impl GammaMethod for RandrGammaMethod {
let conn = self.conn.as_ref().ok_or("Not initialized")?; let conn = self.conn.as_ref().ok_or("Not initialized")?;
let root = self.get_screen_root()?; let root = self.get_screen_root()?;
debug!("Getting screen resources");
/* Get screen resources (list of CRTCs) */ /* Get screen resources (list of CRTCs) */
let res_reply = randr::get_screen_resources_current(conn, root) let res_reply = randr::get_screen_resources_current(conn, root)
.map_err(|e| format!("Failed to get screen resources: {}", e))? .map_err(|e| format!("Failed to get screen resources: {}", e))?
@@ -155,11 +180,12 @@ impl GammaMethod for RandrGammaMethod {
.map_err(|e| format!("RANDR Get Screen Resources Current returned error: {}", e))?; .map_err(|e| format!("RANDR Get Screen Resources Current returned error: {}", e))?;
let crtcs = res_reply.crtcs; let crtcs = res_reply.crtcs;
info!("Found {} CRTCs", crtcs.len());
/* Save CRTC state and gamma ramps */ /* Save CRTC state and gamma ramps */
for crtc in crtcs { for (idx, crtc) in crtcs.iter().enumerate() {
/* Get gamma ramp size */ /* Get gamma ramp size */
let gamma_size_reply = randr::get_crtc_gamma_size(conn, crtc) let gamma_size_reply = randr::get_crtc_gamma_size(conn, *crtc)
.map_err(|e| format!("Failed to get CRTC gamma size: {}", e))? .map_err(|e| format!("Failed to get CRTC gamma size: {}", e))?
.reply() .reply()
.map_err(|e| format!("RANDR Get CRTC Gamma Size returned error: {}", e))?; .map_err(|e| format!("RANDR Get CRTC Gamma Size returned error: {}", e))?;
@@ -167,12 +193,14 @@ impl GammaMethod for RandrGammaMethod {
let ramp_size = gamma_size_reply.size; let ramp_size = gamma_size_reply.size;
if ramp_size == 0 { if ramp_size == 0 {
eprintln!("Warning: CRTC has gamma ramp size 0, skipping"); warn!("CRTC {} has gamma ramp size 0, skipping", idx);
continue; continue;
} }
debug!("CRTC {}: ramp_size={}", idx, ramp_size);
/* Get current gamma ramps */ /* Get current gamma ramps */
let gamma_get_reply = randr::get_crtc_gamma(conn, crtc) let gamma_get_reply = randr::get_crtc_gamma(conn, *crtc)
.map_err(|e| format!("Failed to get CRTC gamma: {}", e))? .map_err(|e| format!("Failed to get CRTC gamma: {}", e))?
.reply() .reply()
.map_err(|e| format!("RANDR Get CRTC Gamma returned error: {}", e))?; .map_err(|e| format!("RANDR Get CRTC Gamma returned error: {}", e))?;
@@ -183,8 +211,10 @@ impl GammaMethod for RandrGammaMethod {
saved_ramps.extend_from_slice(&gamma_get_reply.green); saved_ramps.extend_from_slice(&gamma_get_reply.green);
saved_ramps.extend_from_slice(&gamma_get_reply.blue); saved_ramps.extend_from_slice(&gamma_get_reply.blue);
trace!("CRTC {}: saved {} gamma ramp values", idx, saved_ramps.len());
self.crtcs.push(CrtcState { self.crtcs.push(CrtcState {
crtc, crtc: *crtc,
ramp_size, ramp_size,
saved_ramps, saved_ramps,
}); });
@@ -194,6 +224,8 @@ impl GammaMethod for RandrGammaMethod {
return Err("No usable CRTCs found".to_string()); return Err("No usable CRTCs found".to_string());
} }
info!("Successfully initialized {} CRTCs for gamma adjustment", self.crtcs.len());
Ok(()) Ok(())
} }
+15 -10
View File
@@ -2,6 +2,7 @@
/// Ported from legacy/src/location-*.c /// Ported from legacy/src/location-*.c
use crate::types::Location; use crate::types::Location;
use log::{debug, error, info, trace};
use std::sync::{Arc, Mutex}; use std::sync::{Arc, Mutex};
use std::thread; use std::thread;
use tokio::sync::oneshot; use tokio::sync::oneshot;
@@ -138,6 +139,7 @@ impl LocationProvider for GeoClue2LocationProvider {
} }
fn start(&mut self) -> Result<(), String> { fn start(&mut self) -> Result<(), String> {
debug!("Starting GeoClue2 location provider");
let location = Arc::clone(&self.location); let location = Arc::clone(&self.location);
let error = Arc::clone(&self.error); let error = Arc::clone(&self.error);
let (shutdown_tx, shutdown_rx) = oneshot::channel(); let (shutdown_tx, shutdown_rx) = oneshot::channel();
@@ -147,7 +149,7 @@ impl LocationProvider for GeoClue2LocationProvider {
let rt = tokio::runtime::Runtime::new().expect("Failed to create tokio runtime"); let rt = tokio::runtime::Runtime::new().expect("Failed to create tokio runtime");
rt.block_on(async move { rt.block_on(async move {
if let Err(e) = geoclue2_async_task(location.clone(), error.clone(), shutdown_rx).await { if let Err(e) = geoclue2_async_task(location.clone(), error.clone(), shutdown_rx).await {
eprintln!("GeoClue2 error: {}", e); error!("GeoClue2 error: {}", e);
let mut err = error.lock().unwrap(); let mut err = error.lock().unwrap();
*err = Some(format!("GeoClue2 error: {}", e)); *err = Some(format!("GeoClue2 error: {}", e));
} }
@@ -158,6 +160,7 @@ impl LocationProvider for GeoClue2LocationProvider {
self.shutdown_tx = Some(shutdown_tx); self.shutdown_tx = Some(shutdown_tx);
// Wait a moment for initial location // Wait a moment for initial location
debug!("Waiting for initial location from GeoClue2");
thread::sleep(std::time::Duration::from_millis(500)); thread::sleep(std::time::Duration::from_millis(500));
Ok(()) Ok(())
@@ -263,13 +266,13 @@ async fn geoclue2_async_task(
// Get GeoClue2 Manager // Get GeoClue2 Manager
let manager = ManagerProxy::new(&conn).await?; let manager = ManagerProxy::new(&conn).await?;
eprintln!("Connected to GeoClue2 Manager"); debug!("Connected to GeoClue2 Manager");
// Get client path // Get client path
let client_path = manager.get_client().await.map_err(|e| { let client_path = manager.get_client().await.map_err(|e| {
format!("Failed to get GeoClue2 client: {}. Make sure location services are enabled and Redshift has permission to access location.", e) format!("Failed to get GeoClue2 client: {}. Make sure location services are enabled and Redshift has permission to access location.", e)
})?; })?;
eprintln!("Got GeoClue2 client path: {:?}", client_path); debug!("Got GeoClue2 client path: {:?}", client_path);
// Create client proxy // Create client proxy
let client = ClientProxy::builder(&conn) let client = ClientProxy::builder(&conn)
@@ -279,19 +282,19 @@ async fn geoclue2_async_task(
// Set desktop ID // Set desktop ID
if let Err(e) = client.set_desktop_id("redshift").await { if let Err(e) = client.set_desktop_id("redshift").await {
eprintln!("Warning: Could not set desktop ID: {}", e); debug!("Could not set desktop ID: {}", e);
} }
// Set distance threshold (50km) // Set distance threshold (50km)
if let Err(e) = client.set_distance_threshold(50000).await { if let Err(e) = client.set_distance_threshold(50000).await {
eprintln!("Warning: Could not set distance threshold: {}", e); debug!("Could not set distance threshold: {}", e);
} }
// Subscribe to location updates // Subscribe to location updates
let mut location_stream = client.receive_location_updated().await?; let mut location_stream = client.receive_location_updated().await?;
// Start the client // Start the client
eprintln!("Starting GeoClue2 client..."); debug!("Starting GeoClue2 client...");
if let Err(e) = client.start().await { if let Err(e) = client.start().await {
let err_str = e.to_string(); let err_str = e.to_string();
if err_str.contains("AccessDenied") || err_str.contains("org.freedesktop.DBus.Error.AccessDenied") { if err_str.contains("AccessDenied") || err_str.contains("org.freedesktop.DBus.Error.AccessDenied") {
@@ -300,12 +303,12 @@ async fn geoclue2_async_task(
return Err(format!("Failed to start GeoClue2 client: {}", err_str).into()); return Err(format!("Failed to start GeoClue2 client: {}", err_str).into());
} }
} }
eprintln!("GeoClue2 client started, waiting for location updates..."); debug!("GeoClue2 client started, waiting for location updates...");
// Try to get initial location from Location property // Try to get initial location from Location property
if let Ok(loc_path) = client.location().await { if let Ok(loc_path) = client.location().await {
if loc_path.as_str() != "/" { if loc_path.as_str() != "/" {
eprintln!("Got initial location path: {:?}", loc_path); debug!("Got initial location path: {:?}", loc_path);
let geo_location_result = GeoLocationProxy::builder(&conn) let geo_location_result = GeoLocationProxy::builder(&conn)
.path(&loc_path) .path(&loc_path)
.unwrap() .unwrap()
@@ -319,7 +322,7 @@ async fn geoclue2_async_task(
lat: lat as f32, lat: lat as f32,
lon: lon as f32, lon: lon as f32,
}); });
eprintln!("Initial location: {:.2}, {:.2}", lat, lon); info!("Initial location from GeoClue2: {:.2}, {:.2}", lat, lon);
} }
} }
} }
@@ -348,10 +351,12 @@ async fn geoclue2_async_task(
lon: lon as f32, lon: lon as f32,
}); });
eprintln!("Location updated: {:.2}, {:.2}", lat, lon); info!("Location updated from GeoClue2: {:.2}, {:.2}", lat, lon);
trace!("New location path: {:?}", new_location_path);
} }
_ = &mut shutdown_rx => { _ = &mut shutdown_rx => {
// Shutdown requested // Shutdown requested
debug!("GeoClue2 shutdown requested");
let _ = client.stop().await; let _ = client.stop().await;
return Ok(()); return Ok(());
} }
+80 -67
View File
@@ -11,12 +11,13 @@ mod signals;
mod solar; mod solar;
mod types; mod types;
use clap::{Parser, ValueEnum}; use clap::{ArgAction, Parser, ValueEnum};
use config::{Config, LocationSource}; use config::{Config, LocationSource};
use gamma::{DummyGammaMethod, GammaMethod}; use gamma::GammaMethod;
use gamma_guard::GammaRestoreGuard; use gamma_guard::GammaRestoreGuard;
use gamma_randr::RandrGammaMethod; use gamma_randr::RandrGammaMethod;
use location::{GeoClue2LocationProvider, LocationProvider, ManualLocationProvider}; use location::{GeoClue2LocationProvider, LocationProvider};
use log::{debug, info, trace};
use std::time::{Duration, SystemTime, UNIX_EPOCH}; use std::time::{Duration, SystemTime, UNIX_EPOCH};
use types::*; use types::*;
@@ -30,7 +31,6 @@ const FADE_LENGTH: i32 = 40;
#[derive(Debug, Clone, Copy, ValueEnum)] #[derive(Debug, Clone, Copy, ValueEnum)]
enum GammaMethodChoice { enum GammaMethodChoice {
Randr, Randr,
Dummy,
} }
#[derive(Parser, Debug)] #[derive(Parser, Debug)]
@@ -57,9 +57,9 @@ struct Args {
#[arg(short = 'p', long)] #[arg(short = 'p', long)]
print: bool, print: bool,
/// Verbose output /// Verbose output (can be repeated: -v=info, -vv=debug, -vvv=trace)
#[arg(short, long)] #[arg(short, long, action = ArgAction::Count)]
verbose: bool, verbose: u8,
/// Day temperature (default: 6500K) /// Day temperature (default: 6500K)
#[arg(short = 't', long, default_value = "6500")] #[arg(short = 't', long, default_value = "6500")]
@@ -249,12 +249,12 @@ fn determine_location_with_ini(
args: &Args, args: &Args,
ini_config: &config_ini::RedshiftConfig, ini_config: &config_ini::RedshiftConfig,
) -> Result<(Location, Config), Box<dyn std::error::Error>> { ) -> Result<(Location, Config), Box<dyn std::error::Error>> {
debug!("Determining location using priority system");
// Priority 1: Command-line argument // Priority 1: Command-line argument
if let Some(loc_str) = &args.location { if let Some(loc_str) = &args.location {
let loc = parse_location(loc_str)?; let loc = parse_location(loc_str)?;
if args.verbose { info!("Using location from command-line: {:.4}, {:.4}", loc.lat, loc.lon);
println!("Using location from command-line: {:.4}, {:.4}", loc.lat, loc.lon);
}
// Load config for other settings // Load config for other settings
let mut config = Config::load().unwrap_or_default(); let mut config = Config::load().unwrap_or_default();
@@ -271,11 +271,9 @@ fn determine_location_with_ini(
if should_save { if should_save {
config.set_location(loc, LocationSource::Manual, None); config.set_location(loc, LocationSource::Manual, None);
config.save().ok(); // Ignore save errors config.save().ok(); // Ignore save errors
if args.verbose { info!("Location saved to configuration file");
println!("Location saved to configuration file."); } else {
} debug!("Location will not be saved (session only)");
} else if args.verbose {
println!("Location will not be saved (session only).");
} }
} }
@@ -287,22 +285,16 @@ fn determine_location_with_ini(
// Priority 2: INI config file manual location // Priority 2: INI config file manual location
if let Some(ini_loc) = ini_config.get_manual_location() { if let Some(ini_loc) = ini_config.get_manual_location() {
if args.verbose { info!("Using location from INI config: {:.4}, {:.4}", ini_loc.lat, ini_loc.lon);
println!("Using location from INI config: {:.4}, {:.4}", ini_loc.lat, ini_loc.lon);
}
return Ok((ini_loc, config)); return Ok((ini_loc, config));
} }
// Priority 3: Try GeoClue2 if it's time for daily check // Priority 3: Try GeoClue2 if it's time for daily check
if config.should_check_geoclue() { if config.should_check_geoclue() {
if args.verbose { info!("Checking for automatic location via GeoClue2...");
eprintln!("Checking for automatic location via GeoClue2...");
}
if let Ok(loc) = try_geoclue2(args.verbose) { if let Ok(loc) = try_geoclue2() {
if args.verbose { info!("Got location from GeoClue2: {:.4}, {:.4}", loc.lat, loc.lon);
println!("Got location from GeoClue2: {:.4}, {:.4}", loc.lat, loc.lon);
}
config.set_location(loc, LocationSource::GeoClue2, None); config.set_location(loc, LocationSource::GeoClue2, None);
config.update_geoclue_check(); config.update_geoclue_check();
@@ -318,20 +310,18 @@ fn determine_location_with_ini(
// Priority 4: Use saved TOML configuration // Priority 4: Use saved TOML configuration
if let Some(saved_loc) = config.get_location() { if let Some(saved_loc) = config.get_location() {
if args.verbose { let source_name = config.location.as_ref().map(|l| match l.source {
let source_name = config.location.as_ref().map(|l| match l.source { LocationSource::Manual => "manual entry",
LocationSource::Manual => "manual entry", LocationSource::Interactive => "interactive selection",
LocationSource::Interactive => "interactive selection", LocationSource::GeoClue2 => "GeoClue2",
LocationSource::GeoClue2 => "GeoClue2", }).unwrap_or("unknown");
}).unwrap_or("unknown");
if let Some(ref city) = config.location.as_ref().and_then(|l| l.city_name.as_ref()) { if let Some(ref city) = config.location.as_ref().and_then(|l| l.city_name.as_ref()) {
println!("Using saved location for {}: {:.4}, {:.4} (from {})", info!("Using saved location for {}: {:.4}, {:.4} (from {})",
city, saved_loc.lat, saved_loc.lon, source_name); city, saved_loc.lat, saved_loc.lon, source_name);
} else { } else {
println!("Using saved location: {:.4}, {:.4} (from {})", info!("Using saved location: {:.4}, {:.4} (from {})",
saved_loc.lat, saved_loc.lon, source_name); saved_loc.lat, saved_loc.lon, source_name);
}
} }
return Ok((saved_loc, config)); return Ok((saved_loc, config));
@@ -355,15 +345,13 @@ fn determine_location_with_ini(
} }
/// Try to get location from GeoClue2 /// Try to get location from GeoClue2
fn try_geoclue2(verbose: bool) -> Result<Location, String> { fn try_geoclue2() -> Result<Location, String> {
let mut provider = GeoClue2LocationProvider::new(); let mut provider = GeoClue2LocationProvider::new();
provider.init()?; provider.init()?;
provider.start()?; provider.start()?;
// Wait for location // Wait for location
if verbose { debug!("Waiting for location from GeoClue2...");
eprintln!("Waiting for location from GeoClue2...");
}
std::thread::sleep(Duration::from_secs(5)); std::thread::sleep(Duration::from_secs(5));
provider.get_location() provider.get_location()
@@ -464,6 +452,25 @@ fn build_transition_scheme(
fn main() -> Result<(), Box<dyn std::error::Error>> { fn main() -> Result<(), Box<dyn std::error::Error>> {
let mut args = Args::parse(); let mut args = Args::parse();
/* Initialize logger based on verbosity level */
let log_level = match args.verbose {
0 => log::LevelFilter::Warn,
1 => log::LevelFilter::Info,
2 => log::LevelFilter::Debug,
_ => log::LevelFilter::Trace,
};
env_logger::Builder::from_default_env()
.filter_level(log_level)
.format_timestamp(if args.verbose >= 2 {
Some(env_logger::fmt::TimestampPrecision::Millis)
} else {
Some(env_logger::fmt::TimestampPrecision::Seconds)
})
.init();
debug!("Logger initialized at level: {:?}", log_level);
/* Install signal handlers for graceful shutdown and mode toggling */ /* Install signal handlers for graceful shutdown and mode toggling */
signals::install_handlers()?; signals::install_handlers()?;
@@ -501,9 +508,9 @@ fn main() -> Result<(), Box<dyn std::error::Error>> {
/* Set up gamma method */ /* Set up gamma method */
let mut gamma_method: Box<dyn GammaMethod> = match args.method { let mut gamma_method: Box<dyn GammaMethod> = match args.method {
GammaMethodChoice::Randr => Box::new(RandrGammaMethod::new()), GammaMethodChoice::Randr => Box::new(RandrGammaMethod::new()),
GammaMethodChoice::Dummy => Box::new(DummyGammaMethod::new()),
}; };
info!("Initializing gamma method: {}", gamma_method.name());
gamma_method.init()?; gamma_method.init()?;
gamma_method.start()?; gamma_method.start()?;
@@ -539,9 +546,15 @@ fn main() -> Result<(), Box<dyn std::error::Error>> {
let mut gamma_guard = GammaRestoreGuard::new(gamma_method.as_mut()); let mut gamma_guard = GammaRestoreGuard::new(gamma_method.as_mut());
/* Apply color temperature */ /* Apply color temperature */
if args.verbose { info!("Period: {}", period.name());
println!("Period: {}", period.name()); debug!(
} "Color temperature: {}K, Brightness: {:.2}, Gamma: {:.2}/{:.2}/{:.2}",
color_setting.temperature,
color_setting.brightness,
color_setting.gamma[0],
color_setting.gamma[1],
color_setting.gamma[2]
);
gamma_guard.get_mut().set_temperature(&color_setting, false)?; gamma_guard.get_mut().set_temperature(&color_setting, false)?;
@@ -552,7 +565,7 @@ fn main() -> Result<(), Box<dyn std::error::Error>> {
} }
/* Continual mode - continuously adjust color temperature */ /* Continual mode - continuously adjust color temperature */
run_continual_mode(&location, &scheme, &mut gamma_guard, args.verbose)?; run_continual_mode(&location, &scheme, &mut gamma_guard)?;
Ok(()) Ok(())
} }
@@ -565,7 +578,6 @@ fn run_continual_mode(
location: &Location, location: &Location,
scheme: &TransitionScheme, scheme: &TransitionScheme,
gamma_guard: &mut GammaRestoreGuard, gamma_guard: &mut GammaRestoreGuard,
verbose: bool,
) -> Result<(), Box<dyn std::error::Error>> { ) -> Result<(), Box<dyn std::error::Error>> {
/* Fade parameters */ /* Fade parameters */
let mut fade_length: i32 = 0; let mut fade_length: i32 = 0;
@@ -583,28 +595,26 @@ fn run_continual_mode(
let mut prev_disabled = true; /* Start as true to trigger initial status print */ let mut prev_disabled = true; /* Start as true to trigger initial status print */
let mut done = false; /* Set to true when starting shutdown fade */ let mut done = false; /* Set to true when starting shutdown fade */
if verbose { debug!("Starting continual mode loop");
println!("Color temperature: {}K", interp.temperature); debug!("Initial color temperature: {}K, Brightness: {:.2}", interp.temperature, interp.brightness);
println!("Brightness: {:.2}", interp.brightness);
}
/* Continuously adjust color temperature */ /* Continuously adjust color temperature */
loop { loop {
/* Check for toggle signal (SIGUSR1) */ /* Check for toggle signal (SIGUSR1) */
if signals::check_toggle() && !done { if signals::check_toggle() && !done {
disabled = !disabled; disabled = !disabled;
if verbose { info!("Status: {}", if disabled { "Disabled" } else { "Enabled" });
println!("Status: {}", if disabled { "Disabled" } else { "Enabled" });
}
} }
/* Check for exit signal (SIGINT/SIGTERM) */ /* Check for exit signal (SIGINT/SIGTERM) */
if signals::is_exiting() { if signals::is_exiting() {
if done { if done {
/* Second signal during fade - stop immediately */ /* Second signal during fade - stop immediately */
debug!("Second exit signal received, stopping immediately");
break; break;
} else { } else {
/* First signal - start shutdown fade */ /* First signal - start shutdown fade */
info!("Exit signal received, starting shutdown fade");
done = true; done = true;
disabled = true; disabled = true;
signals::clear_exiting(); signals::clear_exiting();
@@ -612,8 +622,8 @@ fn run_continual_mode(
} }
/* Print status change */ /* Print status change */
if verbose && disabled != prev_disabled { if disabled != prev_disabled {
println!("Status: {}", if disabled { "Disabled" } else { "Enabled" }); info!("Status: {}", if disabled { "Disabled" } else { "Enabled" });
} }
prev_disabled = disabled; prev_disabled = disabled;
@@ -634,6 +644,7 @@ fn run_continual_mode(
/* Current angular elevation of the sun */ /* Current angular elevation of the sun */
let elevation = solar::solar_elevation(now, location.lat as f64, location.lon as f64); let elevation = solar::solar_elevation(now, location.lat as f64, location.lon as f64);
trace!("Solar elevation: {:.2}°", elevation);
/* Determine period and transition progress */ /* Determine period and transition progress */
let period = if elevation >= scheme.high { let period = if elevation >= scheme.high {
@@ -653,13 +664,14 @@ fn run_continual_mode(
/* Print period if it changed during this update, /* Print period if it changed during this update,
or if we are in the transition period. In transition we or if we are in the transition period. In transition we
print the progress, so we always print it in that case. */ print the progress, so we always print it in that case. */
if verbose && (period != prev_period || period == Period::Transition) { if period != prev_period || period == Period::Transition {
match period { match period {
Period::Transition => { Period::Transition => {
println!("Period: Transition ({:.1}%)", transition_prog * 100.0); info!("Period: Transition ({:.1}%)", transition_prog * 100.0);
debug!("Transition progress: {:.3} (elevation: {:.2}°)", transition_prog, elevation);
} }
_ => { _ => {
println!("Period: {}", period.name()); info!("Period: {}", period.name());
} }
} }
} }
@@ -672,6 +684,7 @@ fn run_continual_mode(
if (fade_length == 0 && color_setting_diff_is_major(&interp, &target_interp)) if (fade_length == 0 && color_setting_diff_is_major(&interp, &target_interp))
|| (fade_length != 0 && color_setting_diff_is_major(&target_interp, &prev_target_interp)) || (fade_length != 0 && color_setting_diff_is_major(&target_interp, &prev_target_interp))
{ {
debug!("Starting fade: {} steps", FADE_LENGTH);
fade_length = FADE_LENGTH; fade_length = FADE_LENGTH;
fade_time = 0; fade_time = 0;
fade_start_interp = interp; fade_start_interp = interp;
@@ -684,8 +697,10 @@ fn run_continual_mode(
let alpha = ease_fade(frac).max(0.0).min(1.0); let alpha = ease_fade(frac).max(0.0).min(1.0);
interpolate_color_settings(&fade_start_interp, &target_interp, alpha, &mut interp); interpolate_color_settings(&fade_start_interp, &target_interp, alpha, &mut interp);
trace!("Fade progress: {}/{} (alpha: {:.3})", fade_time, fade_length, alpha);
if fade_time > fade_length { if fade_time > fade_length {
debug!("Fade complete");
fade_time = 0; fade_time = 0;
fade_length = 0; fade_length = 0;
} }
@@ -693,13 +708,11 @@ fn run_continual_mode(
interp = target_interp; interp = target_interp;
} }
if verbose { if prev_target_interp.temperature != target_interp.temperature {
if prev_target_interp.temperature != target_interp.temperature { info!("Color temperature: {}K", target_interp.temperature);
println!("Color temperature: {}K", target_interp.temperature); }
} if prev_target_interp.brightness != target_interp.brightness {
if prev_target_interp.brightness != target_interp.brightness { debug!("Brightness: {:.2}", target_interp.brightness);
println!("Brightness: {:.2}", target_interp.brightness);
}
} }
/* Adjust temperature */ /* Adjust temperature */
+259
View File
@@ -0,0 +1,259 @@
/// Tests for logging functionality and verbosity levels
use std::process::Command;
#[test]
fn test_no_verbose_flag_shows_minimal_output() {
let output = Command::new("cargo")
.args(&["run", "--", "-l", "40:-74", "-p"])
.output()
.expect("Failed to execute command");
let stderr = String::from_utf8_lossy(&output.stderr);
// With no verbose flag, should not see DEBUG, INFO, or TRACE logs
assert!(!stderr.contains("DEBUG"), "No verbose flag should not show DEBUG logs");
assert!(!stderr.contains("INFO"), "No verbose flag should not show INFO logs");
assert!(!stderr.contains("TRACE"), "No verbose flag should not show TRACE logs");
}
#[test]
fn test_single_v_shows_info_logs() {
let output = Command::new("cargo")
.args(&["run", "--", "-l", "40:-74", "-p", "-v"])
.output()
.expect("Failed to execute command");
let stderr = String::from_utf8_lossy(&output.stderr);
// With -v, should see INFO logs
assert!(stderr.contains("INFO"), "Single -v should show INFO logs");
assert!(stderr.contains("Using location from command-line"), "Should log location source");
assert!(stderr.contains("Initializing gamma method"), "Should log gamma initialization");
// Should not see DEBUG or TRACE
assert!(!stderr.contains("DEBUG"), "Single -v should not show DEBUG logs");
assert!(!stderr.contains("TRACE"), "Single -v should not show TRACE logs");
}
#[test]
fn test_double_v_shows_debug_logs() {
let output = Command::new("cargo")
.args(&["run", "--", "-l", "40:-74", "-p", "-vv"])
.output()
.expect("Failed to execute command");
let stderr = String::from_utf8_lossy(&output.stderr);
// With -vv, should see both INFO and DEBUG logs
assert!(stderr.contains("INFO"), "Double -v should show INFO logs");
assert!(stderr.contains("DEBUG"), "Double -v should show DEBUG logs");
assert!(stderr.contains("Logger initialized at level: Debug"), "Should log logger initialization");
assert!(stderr.contains("CRTC"), "Should log CRTC details");
// Should not see TRACE
assert!(!stderr.contains("TRACE"), "Double -v should not show TRACE logs");
}
#[test]
fn test_triple_v_shows_trace_logs() {
let output = Command::new("cargo")
.args(&["run", "--", "-l", "40:-74", "-p", "-vvv"])
.output()
.expect("Failed to execute command");
let stderr = String::from_utf8_lossy(&output.stderr);
// With -vvv, should see INFO, DEBUG, and TRACE logs
assert!(stderr.contains("INFO"), "Triple -v should show INFO logs");
assert!(stderr.contains("DEBUG"), "Triple -v should show DEBUG logs");
assert!(stderr.contains("TRACE"), "Triple -v should show TRACE logs");
assert!(stderr.contains("Logger initialized at level: Trace"), "Should log trace level");
assert!(stderr.contains("Searching for INI config"), "Should log config search");
assert!(stderr.contains("saved") && stderr.contains("gamma ramp values"), "Should log gamma ramp details");
}
#[test]
fn test_location_logging_from_cli() {
let output = Command::new("cargo")
.args(&["run", "--", "-l", "48.8566:2.3522", "-p", "-v"])
.output()
.expect("Failed to execute command");
let stderr = String::from_utf8_lossy(&output.stderr);
assert!(stderr.contains("Using location from command-line"), "Should log location source");
assert!(stderr.contains("48.8566"), "Should log latitude");
assert!(stderr.contains("2.3522"), "Should log longitude");
}
#[test]
fn test_gamma_initialization_logging() {
let output = Command::new("cargo")
.args(&["run", "--", "-l", "40:-74", "-p", "-v"])
.output()
.expect("Failed to execute command");
let stderr = String::from_utf8_lossy(&output.stderr);
assert!(stderr.contains("Initializing gamma method: randr"), "Should log gamma method");
assert!(stderr.contains("Connected to X server"), "Should log X connection");
assert!(stderr.contains("Found") && stderr.contains("CRTCs"), "Should log CRTC count");
assert!(stderr.contains("Successfully initialized") && stderr.contains("CRTCs"), "Should log success");
}
#[test]
fn test_debug_logging_shows_randr_version() {
let output = Command::new("cargo")
.args(&["run", "--", "-l", "40:-74", "-p", "-vv"])
.output()
.expect("Failed to execute command");
let stderr = String::from_utf8_lossy(&output.stderr);
assert!(stderr.contains("RandR version:"), "Should log RandR version at debug level");
assert!(stderr.contains("Getting screen resources"), "Should log screen resource gathering");
}
#[test]
fn test_trace_logging_shows_gamma_ramp_details() {
let output = Command::new("cargo")
.args(&["run", "--", "-l", "40:-74", "-p", "-vvv"])
.output()
.expect("Failed to execute command");
let stderr = String::from_utf8_lossy(&output.stderr);
assert!(stderr.contains("saved") && stderr.contains("gamma ramp values"),
"Should log saved gamma ramp count at trace level");
// Note: "Setting temperature for CRTC" only appears in continual mode, not print mode
// In print mode, we can check for CRTC details
assert!(stderr.contains("CRTC") && stderr.contains("saved"),
"Should log CRTC details at trace level");
}
#[test]
fn test_config_search_logging() {
let output = Command::new("cargo")
.args(&["run", "--", "-l", "40:-74", "-p", "-vv"])
.output()
.expect("Failed to execute command");
let stderr = String::from_utf8_lossy(&output.stderr);
assert!(stderr.contains("Searching for INI configuration file"),
"Should log config search at debug level");
}
#[test]
fn test_trace_shows_config_search_paths() {
let output = Command::new("cargo")
.args(&["run", "--", "-l", "40:-74", "-p", "-vvv"])
.output()
.expect("Failed to execute command");
let stderr = String::from_utf8_lossy(&output.stderr);
assert!(stderr.contains("Checking:"), "Should show individual config paths at trace level");
}
#[test]
fn test_period_logging() {
let output = Command::new("cargo")
.args(&["run", "--", "-l", "40:-74", "-p", "-v"])
.output()
.expect("Failed to execute command");
let stderr = String::from_utf8_lossy(&output.stderr);
let stdout = String::from_utf8_lossy(&output.stdout);
let combined = format!("{}{}", stderr, stdout);
// Should log the period (Night, Daytime, or Transition)
assert!(combined.contains("Period:"), "Should log current period");
}
#[test]
fn test_color_temperature_logging_at_debug() {
let output = Command::new("cargo")
.args(&["run", "--", "-l", "40:-74", "-p", "-vv"])
.output()
.expect("Failed to execute command");
let stdout = String::from_utf8_lossy(&output.stdout);
let stderr = String::from_utf8_lossy(&output.stderr);
let combined = format!("{}{}", stderr, stdout);
// At debug level, should see color settings in DEBUG logs or output
assert!(combined.contains("Color temperature:"),
"Should show color temperature");
assert!(combined.contains("Brightness:"), "Should show brightness");
assert!(combined.contains("Gamma:"), "Should show gamma values");
}
#[test]
fn test_timestamp_precision_at_debug_level() {
let output = Command::new("cargo")
.args(&["run", "--", "-l", "40:-74", "-p", "-vv"])
.output()
.expect("Failed to execute command");
let stderr = String::from_utf8_lossy(&output.stderr);
// At -vv (debug), timestamps should have millisecond precision
// Format: [2025-10-07T23:35:25.071Z DEBUG ...]
assert!(stderr.contains("Z DEBUG"), "Debug level should have timestamps");
// Check for milliseconds (the .XXX part before Z)
let has_millis = stderr.lines()
.filter(|line| line.contains("DEBUG"))
.any(|line| {
// Look for pattern like .NNN]
line.contains('.') && line.chars()
.skip_while(|&c| c != '.')
.skip(1)
.take(3)
.all(|c| c.is_ascii_digit())
});
assert!(has_millis, "Debug timestamps should include milliseconds");
}
#[test]
fn test_verbosity_count_increments() {
// Test that -vvvv (more than 3) still works and maps to Trace
let output = Command::new("cargo")
.args(&["run", "--", "-l", "40:-74", "-p", "-vvvv"])
.output()
.expect("Failed to execute command");
let stderr = String::from_utf8_lossy(&output.stderr);
// Should still show Trace level (max level)
assert!(stderr.contains("Logger initialized at level: Trace"),
"More than 3 -v flags should still map to Trace");
assert!(stderr.contains("TRACE"), "Should show TRACE logs");
}
#[test]
fn test_logger_initialization_logging() {
let output = Command::new("cargo")
.args(&["run", "--", "-l", "40:-74", "-p", "-vv"])
.output()
.expect("Failed to execute command");
let stderr = String::from_utf8_lossy(&output.stderr);
assert!(stderr.contains("Logger initialized at level:"),
"Should log logger initialization at debug level");
}
#[test]
fn test_location_determination_logging() {
let output = Command::new("cargo")
.args(&["run", "--", "-l", "40:-74", "-p", "-vv"])
.output()
.expect("Failed to execute command");
let stderr = String::from_utf8_lossy(&output.stderr);
assert!(stderr.contains("Determining location using priority system"),
"Should log location determination at debug level");
}