From 42e31ab2b99469aceadd0c18123ae6827ab1d2b5 Mon Sep 17 00:00:00 2001 From: Antoine POPINEAU Date: Fri, 26 Apr 2024 11:44:26 +0200 Subject: [PATCH] Added debug logging option. --- .github/ISSUE_TEMPLATE/bug_report.md | 6 +- .github/ISSUE_TEMPLATE/other-issue.md | 10 -- Cargo.lock | 180 ++++++++++++++++++++++++++ Cargo.toml | 3 + README.md | 2 + contrib/man/tuigreet-1.scd | 4 + src/greeter.rs | 20 ++- src/info.rs | 2 + src/ipc.rs | 19 +++ src/keyboard.rs | 4 + src/macros.rs | 19 ++- src/main.rs | 40 ++++-- src/power.rs | 4 + 13 files changed, 291 insertions(+), 22 deletions(-) delete mode 100644 .github/ISSUE_TEMPLATE/other-issue.md diff --git a/.github/ISSUE_TEMPLATE/bug_report.md b/.github/ISSUE_TEMPLATE/bug_report.md index 44fed8c..53f8af5 100644 --- a/.github/ISSUE_TEMPLATE/bug_report.md +++ b/.github/ISSUE_TEMPLATE/bug_report.md @@ -22,10 +22,14 @@ A clear and concise description of what you expected to happen. **System information:** - Distribution: - - `greetd` version: + - `greetd` version: - `tuigreet` version: - Installation method (from source, package, binary, etc.): - `tuigreet` command line: **Additional context** Add any other context about the problem here. + +**Debug log** +Run `tuigreet` with the `-d [FILE]` option to log tracing information into the +specified file, to append here. diff --git a/.github/ISSUE_TEMPLATE/other-issue.md b/.github/ISSUE_TEMPLATE/other-issue.md deleted file mode 100644 index 34ba091..0000000 --- a/.github/ISSUE_TEMPLATE/other-issue.md +++ /dev/null @@ -1,10 +0,0 @@ ---- -name: Other issue -about: Feature idea, comment, anything, really -title: '' -labels: '' -assignees: '' - ---- - - diff --git a/Cargo.lock b/Cargo.lock index 4bcdf82..ec263af 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -232,6 +232,21 @@ dependencies = [ "libc", ] +[[package]] +name = "crossbeam-channel" +version = "0.5.12" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "ab3db02a9c5b5121e1e42fbdb1aeb65f5e02624cc58c43f2884c6ccac0b82f95" +dependencies = [ + "crossbeam-utils", +] + +[[package]] +name = "crossbeam-utils" +version = "0.8.19" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "248e3bacc7dc6baa3b21e405ee045c3047101a49145e7e9eca583ab4c2ca5345" + [[package]] name = "crossterm" version = "0.27.0" @@ -287,6 +302,15 @@ dependencies = [ "parking_lot_core", ] +[[package]] +name = "deranged" +version = "0.3.11" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "b42b6fa04a440b495c8b04d0e71b707c585f83cb9cb28cf8cd0d976c315e31b4" +dependencies = [ + "powerfmt", +] + [[package]] name = "digest" version = "0.10.7" @@ -792,6 +816,22 @@ dependencies = [ "libc", ] +[[package]] +name = "nu-ansi-term" +version = "0.46.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "77a8165726e8236064dbb45459242600304b42a5ea24ee2948e18e023bf7ba84" +dependencies = [ + "overload", + "winapi", +] + +[[package]] +name = "num-conv" +version = "0.1.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "51d515d32fb182ee37cda2ccdcb92950d6a3c2893aa280e540671c2cd0f3b1d9" + [[package]] name = "num-traits" version = "0.2.18" @@ -865,6 +905,12 @@ dependencies = [ "hashbrown", ] +[[package]] +name = "overload" +version = "0.1.1" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "b15813163c1d831bf4a13c3610c05c0d03b39feb07f7e09fa234dac9b15aaf39" + [[package]] name = "parking_lot" version = "0.12.1" @@ -906,6 +952,12 @@ version = "0.1.0" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "8b870d8c151b6f2fb93e84a13146138f05d02ed11c7e7c54f8826aaaf7c9f184" +[[package]] +name = "powerfmt" +version = "0.2.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "439ee305def115ba05938db6eb1644ff94165c5ab5e9420d1c1bcedbba909391" + [[package]] name = "ppv-lite86" version = "0.2.17" @@ -1198,6 +1250,15 @@ dependencies = [ "digest", ] +[[package]] +name = "sharded-slab" +version = "0.1.7" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "f40ca3c46823713e0d4209592e8d6e826aa57e928f09752619fc696c499637f6" +dependencies = [ + "lazy_static", +] + [[package]] name = "signal-hook" version = "0.3.17" @@ -1366,6 +1427,47 @@ dependencies = [ "syn 2.0.60", ] +[[package]] +name = "thread_local" +version = "1.1.8" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "8b9ef9bad013ada3808854ceac7b46812a6465ba368859a37e2100283d2d719c" +dependencies = [ + "cfg-if", + "once_cell", +] + +[[package]] +name = "time" +version = "0.3.36" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "5dfd88e563464686c916c7e46e623e520ddc6d79fa6641390f2e3fa86e83e885" +dependencies = [ + "deranged", + "itoa", + "num-conv", + "powerfmt", + "serde", + "time-core", + "time-macros", +] + +[[package]] +name = "time-core" +version = "0.1.2" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "ef927ca75afb808a4d64dd374f00a2adf8d0fcff8e7b184af886c3c87ec4a3f3" + +[[package]] +name = "time-macros" +version = "0.2.18" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "3f252a68540fde3a3877aeea552b832b40ab9a69e318efd078774a01ddee1ccf" +dependencies = [ + "num-conv", + "time-core", +] + [[package]] name = "tiny-keccak" version = "2.0.2" @@ -1456,6 +1558,75 @@ dependencies = [ "winnow", ] +[[package]] +name = "tracing" +version = "0.1.40" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "c3523ab5a71916ccf420eebdf5521fcef02141234bbc0b8a49f2fdc4544364ef" +dependencies = [ + "pin-project-lite", + "tracing-attributes", + "tracing-core", +] + +[[package]] +name = "tracing-appender" +version = "0.2.3" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "3566e8ce28cc0a3fe42519fc80e6b4c943cc4c8cef275620eb8dac2d3d4e06cf" +dependencies = [ + "crossbeam-channel", + "thiserror", + "time", + "tracing-subscriber", +] + +[[package]] +name = "tracing-attributes" +version = "0.1.27" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "34704c8d6ebcbc939824180af020566b01a7c01f80641264eba0999f6c2b6be7" +dependencies = [ + "proc-macro2", + "quote", + "syn 2.0.60", +] + +[[package]] +name = "tracing-core" +version = "0.1.32" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "c06d3da6113f116aaee68e4d601191614c9053067f9ab7f6edbcb161237daa54" +dependencies = [ + "once_cell", + "valuable", +] + +[[package]] +name = "tracing-log" +version = "0.2.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "ee855f1f400bd0e5c02d150ae5de3840039a3f54b025156404e34c23c03f47c3" +dependencies = [ + "log", + "once_cell", + "tracing-core", +] + +[[package]] +name = "tracing-subscriber" +version = "0.3.18" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "ad0f048c97dbd9faa9b7df56362b8ebcaa52adb06b498c050d2f4e32f90a7a8b" +dependencies = [ + "nu-ansi-term", + "sharded-slab", + "smallvec", + "thread_local", + "tracing-core", + "tracing-log", +] + [[package]] name = "trim-in-place" version = "0.1.7" @@ -1482,6 +1653,9 @@ dependencies = [ "smart-default", "textwrap", "tokio", + "tracing", + "tracing-appender", + "tracing-subscriber", "unic-langid", "uzers", "zeroize", @@ -1555,6 +1729,12 @@ dependencies = [ "log", ] +[[package]] +name = "valuable" +version = "0.1.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "830b7e5d4d90034032940e4ace0d9a9a057e7a45cd94e6c007832e39edb82f6d" + [[package]] name = "version_check" version = "0.9.4" diff --git a/Cargo.toml b/Cargo.toml index 1c59742..23f75fe 100644 --- a/Cargo.toml +++ b/Cargo.toml @@ -41,6 +41,9 @@ unic-langid = "^0.9" zeroize = "^1.3" uzers = "0.12" rand = "0.8.5" +tracing-appender = "0.2.3" +tracing-subscriber = "0.3.18" +tracing = "0.1.40" [profile.release] lto = true diff --git a/README.md b/README.md index dcb9b40..a004e99 100644 --- a/README.md +++ b/README.md @@ -10,6 +10,8 @@ Usage: tuigreet [OPTIONS] Options: -h, --help show this usage information -v, --version print version information + -d, --debug [FILE] enable debug logging to the provided file, or to + /tmp/tuigreet.log -c, --cmd COMMAND command to run -s, --sessions DIRS colon-separated list of Wayland session paths --session-wrapper 'CMD [ARGS]...' diff --git a/contrib/man/tuigreet-1.scd b/contrib/man/tuigreet-1.scd index a3446b0..d0a238d 100644 --- a/contrib/man/tuigreet-1.scd +++ b/contrib/man/tuigreet-1.scd @@ -16,6 +16,10 @@ tuigreet - A graphical console greeter for greetd *-v, --version* Print program version and exit. +*-d, --debug [FILE]* + Enables debug logging to the provided FILE path, or to /tmp/tuigreet.log if no + file is specified. + *-c, --cmd CMD* Specify which command to run on successful authentication. This can be overridden by manual selection within *tuigreet*. diff --git a/src/greeter.rs b/src/greeter.rs index 39e1f2e..0ec0f36 100644 --- a/src/greeter.rs +++ b/src/greeter.rs @@ -34,6 +34,7 @@ use crate::{ }, }; +const DEFAULT_LOG_FILE: &str = "/tmp/tuigreet.log"; const DEFAULT_LOCALE: Locale = Locale::en_US; const DEFAULT_ASTERISKS_CHARS: &str = "*"; // `startx` wants an absolute path to the executable as a first argument. @@ -91,6 +92,9 @@ impl SecretDisplay { #[derive(SmartDefault)] pub struct Greeter { + pub debug: bool, + pub logfile: String, + #[default(DEFAULT_LOCALE)] pub locale: Locale, pub config: Option, @@ -354,6 +358,7 @@ impl Greeter { opts.optflag("h", "help", "show this usage information"); opts.optflag("v", "version", "print version information"); + opts.optflagopt("d", "debug", "enable debug logging to the provided file, or to /tmp/tuigreet.log", "FILE"); opts.optopt("c", "cmd", "command to run", "COMMAND"); opts.optopt("s", "sessions", "colon-separated list of Wayland session paths", "DIRS"); opts.optopt("", "session-wrapper", "wrapper command to initialize the non-X11 session", "'CMD [ARGS]...'"); @@ -419,6 +424,15 @@ impl Greeter { } } + if self.config().opt_present("debug") { + self.debug = true; + + self.logfile = match self.config().opt_str("debug") { + Some(file) => file.to_string(), + None => DEFAULT_LOG_FILE.to_string(), + } + } + if self.config().opt_present("issue") && self.config().opt_present("greeting") { eprintln!("Only one of --issue and --greeting may be used at the same time"); print_usage(opts); @@ -455,6 +469,8 @@ impl Greeter { let max_uid = self.config().opt_str("user-menu-max-uid").and_then(|uid| uid.parse::().ok()); let (min_uid, max_uid) = get_min_max_uids(min_uid, max_uid); + tracing::info!("min/max UIDs are {}/{}", min_uid, max_uid); + if min_uid >= max_uid { eprintln!("Minimum UID ({min_uid}) must be less than maximum UID ({max_uid})"); process::exit(1); @@ -464,7 +480,9 @@ impl Greeter { title: fl!("title_users"), options: get_users(min_uid, max_uid), selected: 0, - } + }; + + tracing::info!("found {} users", self.users.options.len()); } if self.config().opt_present("remember-session") && self.config().opt_present("remember-user-session") { diff --git a/src/info.rs b/src/info.rs index 13cd616..0437452 100644 --- a/src/info.rs +++ b/src/info.rs @@ -229,6 +229,8 @@ pub fn get_sessions(greeter: &Greeter) -> Result, Box> { files.sort_by(|a, b| a.name.cmp(&b.name)); + tracing::info!("found {} sessions", files.len()); + Ok(files) } diff --git a/src/ipc.rs b/src/ipc.rs index e9161e4..d658b02 100644 --- a/src/ipc.rs +++ b/src/ipc.rs @@ -9,6 +9,7 @@ use tokio::sync::{ use crate::{ event::Event, info::{delete_last_user_session, delete_last_user_session_path, write_last_user_session, write_last_user_session_path, write_last_username}, + macros::SafeDebug, ui::sessions::{Session, SessionSource, SessionType}, AuthStatus, Greeter, Mode, }; @@ -32,6 +33,8 @@ impl Ipc { } pub async fn send(&self, request: Request) { + tracing::info!("sending request to greetd: {}", request.safe_repr()); + let _ = self.0.tx.read().await.send(request).await; } @@ -66,6 +69,8 @@ impl Ipc { } async fn parse_response(&mut self, greeter: &mut Greeter, response: Response) -> Result<(), Box> { + tracing::info!("received greetd message: {:?}", response); + match response { Response::AuthMessage { auth_message_type, auth_message } => match auth_message_type { AuthMessageType::Secret => { @@ -107,18 +112,26 @@ impl Ipc { Response::Success => { if greeter.done { + tracing::info!("greetd acknowledged session start, exiting"); + if greeter.remember { + tracing::info!("caching last successful username"); + write_last_username(&greeter.username); if greeter.remember_user_session { match greeter.session_source { SessionSource::Command(ref command) => { + tracing::info!("caching last user command: {command}"); + write_last_user_session(&greeter.username.value, command); delete_last_user_session_path(&greeter.username.value); } SessionSource::Session(index) => { if let Some(Session { path: Some(session_path), .. }) = greeter.sessions.options.get(index) { + tracing::info!("caching last user session: {session_path:?}"); + write_last_user_session_path(&greeter.username.value, session_path); delete_last_user_session(&greeter.username.value); } @@ -133,6 +146,8 @@ impl Ipc { let _ = sender.send(Event::Exit(AuthStatus::Success)).await; } } else { + tracing::info!("authentication successful, starting session"); + let command = greeter.session_source.command(greeter).map(str::to_string); if let Some(command) = command { @@ -162,6 +177,8 @@ impl Ipc { } Response::Error { error_type, description } => { + tracing::info!("received an error from greetd: {error_type:?} - {description}"); + Ipc::cancel(greeter).await; match error_type { @@ -187,6 +204,8 @@ impl Ipc { } pub async fn cancel(greeter: &mut Greeter) { + tracing::info!("cancelling session"); + let _ = Request::CancelSession.write_to(&mut *greeter.stream().await).await; } } diff --git a/src/keyboard.rs b/src/keyboard.rs index 14e70fe..bde94c3 100644 --- a/src/keyboard.rs +++ b/src/keyboard.rs @@ -367,12 +367,16 @@ async fn validate_username(greeter: &mut Greeter, ipc: &Ipc) { if greeter.remember_user_session { if let Ok(last_session) = get_last_user_session_path(&greeter.username.value) { if let Some(last_session) = Session::from_path(greeter, last_session).cloned() { + tracing::info!("remembered user session is {}", last_session.name); + greeter.sessions.selected = greeter.sessions.options.iter().position(|sess| sess.path == last_session.path).unwrap_or(0); greeter.session_source = SessionSource::Session(greeter.sessions.selected); } } if let Ok(command) = get_last_user_session(&greeter.username.value) { + tracing::info!("remembered user command is {}", command); + greeter.session_source = SessionSource::Command(command); } } diff --git a/src/macros.rs b/src/macros.rs index 90941cb..d1661cb 100644 --- a/src/macros.rs +++ b/src/macros.rs @@ -1,9 +1,26 @@ +use greetd_ipc::Request; + +pub trait SafeDebug { + fn safe_repr(&self) -> String; +} + +impl SafeDebug for Request { + fn safe_repr(&self) -> String { + match self { + msg @ &Request::CancelSession => format!("{:?}", msg), + msg @ &Request::CreateSession { .. } => format!("{:?}", msg), + &Request::PostAuthMessageResponse { .. } => "PostAuthMessageResponse".to_string(), + msg @ &Request::StartSession { .. } => format!("{:?}", msg), + } + } +} + macro_rules! fl { ($message_id:literal) => {{ i18n_embed_fl::fl!($crate::ui::MESSAGES, $message_id) }}; ($message_id:literal, $($args:expr),*) => {{ - i18n_embed_fl::fl!($crate::ui::MESSAGES, $message_id, $($args), *) + i18n_embed_fl::fl!($crate::ui::MESSAGES, $message_id, $($args),*) }}; } diff --git a/src/main.rs b/src/main.rs index 767ce60..4fc5c05 100644 --- a/src/main.rs +++ b/src/main.rs @@ -12,7 +12,7 @@ mod keyboard; mod power; mod ui; -use std::{error::Error, io, process, sync::Arc}; +use std::{error::Error, fs::OpenOptions, io, process, sync::Arc}; use crossterm::{ execute, @@ -21,6 +21,7 @@ use crossterm::{ use event::Event; use greetd_ipc::Request; use tokio::sync::RwLock; +use tracing_appender::non_blocking::WorkerGuard; use tui::{backend::CrosstermBackend, Terminal}; pub use self::greeter::*; @@ -42,6 +43,10 @@ async fn run() -> Result<(), Box> { let mut greeter = Greeter::new(events.sender()).await; let mut stdout = io::stdout(); + let _guard = init_logger(&greeter); + + tracing::info!("tuigreet started"); + register_panic_handler(); enable_raw_mode()?; @@ -57,6 +62,8 @@ async fn run() -> Result<(), Box> { if greeter.remember && !greeter.username.value.is_empty() { greeter.working = true; + tracing::info!("creating remembered session for user {}", greeter.username.value); + ipc .send(Request::CreateSession { username: greeter.username.value.clone(), @@ -79,6 +86,8 @@ async fn run() -> Result<(), Box> { loop { if let Some(status) = greeter.read().await.exit { + tracing::info!("exiting main loop"); + return Err(status.into()); } @@ -100,6 +109,8 @@ async fn run() -> Result<(), Box> { } async fn exit(greeter: &mut Greeter, status: AuthStatus) { + tracing::info!("preparing exit with status {}", status); + match status { AuthStatus::Success => {} AuthStatus::Cancel | AuthStatus::Failure => Ipc::cancel(greeter).await, @@ -133,14 +144,25 @@ pub fn clear_screen() { } } -#[cfg(debug_assertions)] -pub fn log(msg: &str) { - use std::io::Write; +fn init_logger(greeter: &Greeter) -> Option { + use tracing_subscriber::filter::{LevelFilter, Targets}; + use tracing_subscriber::prelude::*; - let time = chrono::Utc::now(); + let logfile = OpenOptions::new().write(true).create(true).append(true).clone(); - let mut file = std::fs::OpenOptions::new().create(true).append(true).open("/tmp/tuigreet.log").unwrap(); - file.write_all(format!("{:?} - ", time).as_ref()).unwrap(); - file.write_all(msg.as_ref()).unwrap(); - file.write_all("\n".as_bytes()).unwrap(); + match (greeter.debug, logfile.open(&greeter.logfile)) { + (true, Ok(file)) => { + let (appender, guard) = tracing_appender::non_blocking(file); + let target = Targets::new().with_target("tuigreet", LevelFilter::DEBUG); + + tracing_subscriber::registry() + .with(tracing_subscriber::fmt::layer().with_writer(appender).with_line_number(true)) + .with(target) + .init(); + + Some(guard) + } + + _ => None, + } } diff --git a/src/power.rs b/src/power.rs index 58a7a95..34d457f 100644 --- a/src/power.rs +++ b/src/power.rs @@ -61,6 +61,8 @@ pub async fn power(greeter: &mut Greeter, option: PowerOption) { } pub async fn run(greeter: &Arc>, mut command: Command) { + tracing::info!("executing power command: {:?}", command); + greeter.write().await.mode = Mode::Processing; let message = match command.output().await { @@ -77,6 +79,8 @@ pub async fn run(greeter: &Arc>, mut command: Command) { Err(err) => Some(format!("{}: {err}", fl!("command_failed"))), }; + tracing::info!("power command exited with: {:?}", message); + let mode = greeter.read().await.previous_mode; let mut greeter = greeter.write().await;