diff src/logging.rs @ 92:5ddbcada30f2

Add the ability to log against a PAM handle. PAM impls provide a way to log to syslog. This exposes it via nonstick.
author Paul Fisher <paul@pfish.zone>
date Sun, 22 Jun 2025 19:29:32 -0400
parents
children b87100c5eed4
line wrap: on
line diff
--- /dev/null	Thu Jan 01 00:00:00 1970 +0000
+++ b/src/logging.rs	Sun Jun 22 19:29:32 2025 -0400
@@ -0,0 +1,192 @@
+//! PAM logging variables and macros.
+//!
+//! PAM implementations usually include the ability to log to syslog in a way
+//! that is associated with the log entry itself. This module defines the enums
+//! and macros for logging.
+//!
+//! For more details, see [`PamShared::log`](crate::PamShared::log).
+//!
+//! We can't use [the `log` crate](https://docs.rs/log) because that requires
+//! that any `Log` implementors be `Sync` and `Send`, and a PAM handle
+//! may be neither. Furthermore, PAM handles are passed to PAM modules in
+//! dynamic libraries, and `log` doesn't work across dynamic linking boundaries.
+//!
+//! A `PamShared` implementation may still use the `log` crate on the backend,
+//! and may even itself implement `log::Log`, but that interface is not exposed
+//! to the generic PAM user.
+
+#[cfg(feature = "link")]
+mod levels {
+    pub use internal::*;
+    #[cfg(pam_impl = "linux-pam")]
+    mod internal {
+        use crate::libpam::pam_ffi;
+        pub const ERROR: u32 = pam_ffi::LOG_ERR;
+        pub const WARN: u32 = pam_ffi::LOG_WARNING;
+        pub const INFO: u32 = pam_ffi::LOG_INFO;
+        pub const DEBUG: u32 = pam_ffi::LOG_DEBUG;
+    }
+    #[cfg(pam_impl = "openpam")]
+    mod internal {
+        use crate::libpam::pam_ffi;
+        pub const ERROR: u32 = pam_ffi::PAM_LOG_ERROR;
+        pub const WARN: u32 = pam_ffi::PAM_LOG_NOTICE;
+        pub const INFO: u32 = pam_ffi::PAM_LOG_VERBOSE;
+        pub const DEBUG: u32 = pam_ffi::PAM_LOG_DEBUG;
+    }
+}
+
+#[cfg(not(feature = "link"))]
+mod levels {
+    pub const ERROR: u32 = 2255887;
+    pub const WARN: u32 = 7265000;
+    pub const INFO: u32 = 7762323;
+    pub const DEBUG: u32 = 8675309;
+}
+
+/// An entry to be added to the log.
+///
+/// The levels are in descending order of importance and correspond roughly
+/// to the similarly-named levels in the `log` crate.
+///
+/// In all implementations, these are ordered such that `Error`, `Warning`,
+/// `Info`, and `Debug` are in ascending order.
+#[derive(Debug, PartialEq, Ord, PartialOrd, Eq)]
+#[repr(u32)]
+pub enum Level {
+    Error = levels::ERROR,
+    Warning = levels::WARN,
+    Info = levels::INFO,
+    Debug = levels::DEBUG,
+}
+
+/// Here's the guts of the logger thingy. You shouldn't be using this!
+#[doc(hidden)]
+#[macro_export]
+macro_rules! __log_internal {
+    ($handle:expr, $level:ident, $($arg:tt)+) => {
+        $handle.log($crate::logging::Level::$level, &format!($($arg)+));
+    }
+}
+
+/// Logs a message at error level via the given PAM handle.
+///
+/// This supports `format!`-style formatting.
+///
+/// # Example
+///
+/// ```no_run
+/// # let pam_handle: Box<dyn nonstick::PamShared> = unimplemented!();
+/// # let load_error = "xxx";
+/// nonstick::error!(pam_handle, "error loading data from data source: {load_error}");
+/// // Will log a message like "error loading data from data source: timed out"
+/// // at ERROR level on syslog.
+/// ```
+#[macro_export]
+macro_rules! error { ($handle:expr, $($arg:tt)+) => { $crate::__log_internal!($handle, Error, $($arg)+);}}
+
+/// Logs a message at warning level via the given PAM handle.
+///
+/// This supports `format!`-style formatting.
+///
+/// # Example
+///
+/// ```no_run
+/// # let pam_handle: Box<dyn nonstick::PamShared> = unimplemented!();
+/// # let latency_ms = "xxx";
+/// nonstick::warn!(pam_handle, "loading took too long: {latency_ms} ms");
+/// // Will log a message like "loading took too long: 495 ms"
+/// // at WARN level on syslog.
+/// ```
+#[macro_export]
+macro_rules! warn { ($handle:expr, $($arg:tt)+) => { $crate::__log_internal!($handle, Warning, $($arg)+);}}
+
+/// Logs a message at info level via the given PAM handle.
+///
+/// This supports `format!`-style formatting.
+///
+/// # Example
+///
+/// ```no_run
+/// # let pam_handle: Box<dyn nonstick::PamShared> = unimplemented!();
+/// nonstick::info!(pam_handle, "using remote backend to load user data");
+/// // Will log a message like "using remote backend to load user data"
+/// // at INFO level on syslog.
+/// ```
+#[macro_export]
+macro_rules! info { ($handle:expr, $($arg:tt)+) => { $crate::__log_internal!($handle, Info, $($arg)+);}}
+
+/// Logs a message at debug level via the given PAM handle.
+///
+/// This level specially includes file/line/column information.
+/// This supports `format!`-style formatting.
+///
+/// # Example
+///
+/// ```no_run
+/// # let pam_handle: Box<dyn nonstick::PamShared> = unimplemented!();
+/// # let userinfo_url = "https://zombo.com/";
+/// nonstick::debug!(pam_handle, "making HTTP GET request to {userinfo_url}");
+/// // Will log a message like
+/// // "pam_http/lib.rs:39:14: making HTTP GET request to https://zombo.com/"
+/// // at DEBUG level on syslog.
+/// ```
+#[macro_export]
+macro_rules! debug {($handle:expr, $($arg:tt)+) => {
+    $crate::__log_internal!(
+        $handle, Debug,
+        "{}:{}:{}: {}", file!(), line!(), column!(), format_args!($($arg)+),
+    );
+}}
+
+#[cfg(test)]
+mod tests {
+    use super::*;
+    use regex::Regex;
+    use std::cell::RefCell;
+
+    #[test]
+    fn test_order() {
+        assert!(Level::Error < Level::Warning);
+        assert!(Level::Warning < Level::Info);
+        assert!(Level::Info < Level::Debug);
+    }
+
+    #[test]
+    fn test_logging() {
+        struct Logger(RefCell<Vec<(Level, String)>>);
+
+        impl Logger {
+            fn log(&self, level: Level, text: &str) {
+                self.0.borrow_mut().push((level, text.to_owned()))
+            }
+        }
+
+        let logger = Logger(Default::default());
+
+        let something = Level::Error;
+        error!(logger, "here is another thing: {}", 99);
+        warn!(logger, "watch out!");
+        info!(logger, "here is some info: {info}", info = "information");
+        debug!(logger, "here is something: {something:?}");
+
+        let mut logged = logger.0.into_inner();
+
+        let (last_level, last_string) = logged.pop().unwrap();
+        assert_eq!(Level::Debug, last_level);
+        let expr = Regex::new(r"^[^:]+:\d+:\d+: here is something: Error$").unwrap();
+        assert!(
+            expr.is_match(&last_string),
+            "{last_string:?} did not match {expr:?}"
+        );
+
+        assert_eq!(
+            vec![
+                (Level::Error, "here is another thing: 99".to_owned()),
+                (Level::Warning, "watch out!".to_owned()),
+                (Level::Info, "here is some info: information".to_owned()),
+            ],
+            logged
+        );
+    }
+}