From e677ad55d5f37862ed2c54be2e06f38fecb1353e Mon Sep 17 00:00:00 2001 From: Josh Megnauth Date: Tue, 29 Jul 2025 02:36:08 -0400 Subject: [PATCH] Better priorities & LOG_UPTO for syslog.h * Fix PERROR to match musl/glibc better * More unit tests + enabled on Linux * Pack priority and facility into one i32 and check the bits with bitflags * Add LOG_UPTO (logic is straight from musl) Not done: * "%m" - this could just be added to printf * LOG_CONS --- include/bits/syslog.h | 6 - src/header/sys_syslog/cbindgen.toml | 1 - src/header/sys_syslog/logger.rs | 160 ++++++++++++++---- src/header/sys_syslog/mod.rs | 60 ++++--- tests/Makefile | 5 +- tests/expected/bins_dynamic/sys_syslog.stderr | 13 ++ tests/expected/bins_dynamic/sys_syslog.stdout | 0 tests/expected/bins_static/sys_syslog.stderr | 13 ++ tests/expected/bins_static/sys_syslog.stdout | 0 tests/sys_syslog/syslog.c | 46 +++++ tests/syslog/syslog.c | 29 ---- 11 files changed, 245 insertions(+), 88 deletions(-) delete mode 100644 include/bits/syslog.h create mode 100644 tests/expected/bins_dynamic/sys_syslog.stderr create mode 100644 tests/expected/bins_dynamic/sys_syslog.stdout create mode 100644 tests/expected/bins_static/sys_syslog.stderr create mode 100644 tests/expected/bins_static/sys_syslog.stdout create mode 100644 tests/sys_syslog/syslog.c delete mode 100644 tests/syslog/syslog.c diff --git a/include/bits/syslog.h b/include/bits/syslog.h deleted file mode 100644 index 06fe014db3..0000000000 --- a/include/bits/syslog.h +++ /dev/null @@ -1,6 +0,0 @@ -#ifndef _BITS_SYSLOG_H -#define _BITS_SYSLOG_H - -#define LOG_MASK(pri) (1<<(pri)) - -#endif diff --git a/src/header/sys_syslog/cbindgen.toml b/src/header/sys_syslog/cbindgen.toml index 082186f4ea..2d51f31eb7 100644 --- a/src/header/sys_syslog/cbindgen.toml +++ b/src/header/sys_syslog/cbindgen.toml @@ -1,4 +1,3 @@ -sys_includes = ["bits/syslog.h"] include_guard = "_RELIBC_SYS_SYSLOG_H" language = "C" style = "Type" diff --git a/src/header/sys_syslog/logger.rs b/src/header/sys_syslog/logger.rs index 53182290f0..4629188e68 100644 --- a/src/header/sys_syslog/logger.rs +++ b/src/header/sys_syslog/logger.rs @@ -18,10 +18,16 @@ use crate::{ sync::Mutex, }; -use bitflags::bitflags; +use bitflags::{bitflags, Flags}; use chrono::{DateTime, Utc}; -use super::{sys::LogFile, LOG_CONS, LOG_NDELAY, LOG_NOWAIT, LOG_ODELAY, LOG_PERROR, LOG_PID}; +use super::{ + sys::LogFile, LOG_ALERT, LOG_AUTH, LOG_AUTHPRIV, LOG_CONS, LOG_CRIT, LOG_CRON, LOG_DAEMON, + LOG_DEBUG, LOG_EMERG, LOG_ERR, LOG_FTP, LOG_INFO, LOG_KERN, LOG_LOCAL0, LOG_LOCAL1, LOG_LOCAL2, + LOG_LOCAL3, LOG_LOCAL4, LOG_LOCAL5, LOG_LOCAL6, LOG_LOCAL7, LOG_LPR, LOG_MAIL, LOG_MASK, + LOG_NDELAY, LOG_NEWS, LOG_NOTICE, LOG_NOWAIT, LOG_ODELAY, LOG_PERROR, LOG_PID, LOG_SYSLOG, + LOG_UPTO, LOG_USER, LOG_UUCP, LOG_WARNING, +}; pub(super) static LOGGER: Mutex> = Mutex::new(LogParams::new(None)); @@ -30,8 +36,7 @@ pub struct LogParams { /// but the program name is a common default. ident: String, pub opt: Config, - pub facility: c_int, - pub mask: c_int, + pub mask: Priority, writer: Option, } @@ -40,36 +45,44 @@ impl LogParams { LogParams { ident: String::new(), opt: Config::DelayOpen, - facility: super::LOG_USER, - mask: 0xff, + mask: Priority::from_bits_truncate(Priority::User.bits() | Priority::UpToDebug.bits()), writer, } } - pub fn write_log(&mut self, mut priority: c_int, message: *const c_char, mut ap: VaList) { - let mut epoch: i64 = 0; - unsafe { - epoch = time(null_mut()); + pub fn write_log(&mut self, priority: Priority, message: CStr<'_>, mut ap: VaList) { + if message.is_empty() { + return; } - let currtime: DateTime = - DateTime::from_timestamp(epoch, 0).expect("Couldn't retrieve broken-down time."); + if self.ident.is_empty() { + self.set_identity(None); + } + + let epoch = unsafe { time(null_mut()) }; + let currtime: DateTime = DateTime::from_timestamp(epoch, 0).unwrap_or_default(); let currtime_s = currtime.format("%b %e %T %Y"); let pid = self.opt.contains(Config::Pid).then(|| getpid()); - if ((priority & super::LOG_FACMASK) == 0) { - priority |= self.facility - }; // journald from systemd rewrites log messages from syslog into its own style. We'll // still use the same style as other libc even though it's implementation specific. let mut buffer = if let Some(pid) = pid { - format!("<{}>{} {}{}: ", priority, currtime_s, self.ident, pid).into_bytes() + format!( + "<{}>{} {}{}: ", + priority.bits(), + currtime_s, + self.ident, + pid + ) + .into_bytes() } else { - format!("<{}>{} {}: ", priority, currtime_s, self.ident).into_bytes() + format!("<{}>{} {}: ", priority.bits(), currtime_s, self.ident).into_bytes() }; + let prefix = buffer.len(); + // SAFETY: // * Assumes caller passed in a valid C string; printf should handle that invariant. // * `buffer` grows to fit the formatted string. - unsafe { printf(&mut buffer, message, ap) }; + unsafe { printf(&mut buffer, message.as_ptr(), ap) }; buffer.extend(b"\n\0"); if self.maybe_open_logger().is_ok() { @@ -97,9 +110,17 @@ impl LogParams { } } if self.opt.contains(Config::PError) { - // SAFETY: `buffer` is a valid byte string that is NUL terminated. + // SAFETY: + // * `ident` is a valid byte string that is NUL terminated when set. + // * `buffer` is a valid byte string that is NUL terminated above. unsafe { - fprintf(stderr, c"%s".as_ptr(), buffer.as_ptr() as *const c_char); + // musl and glibc only print the message rather than the prefix + message to stderr + fprintf( + stderr, + c"%s: %s".as_ptr(), + self.ident.as_ptr() as *const c_char, + buffer[prefix..].as_ptr() as *const c_char, + ); } } } @@ -110,8 +131,7 @@ impl LogParams { pub fn set_identity_cstr(&mut self, ident: Option>) { let ident = ident .and_then(|ident| (!ident.is_empty()).then(|| ident.to_str().ok())) - .flatten() - .map(ToString::to_string); + .flatten(); self.set_identity(ident); } @@ -119,13 +139,22 @@ impl LogParams { /// /// The log identity is prepended to each message. If unset, the program name will be used as a /// default. - pub fn set_identity(&mut self, ident: Option) { - self.ident = ident.unwrap_or_else(|| { - unsafe { CStr::from_nullable_ptr(platform::program_invocation_short_name) } - .and_then(|name| name.to_str().ok()) - .unwrap_or_default() - .to_owned() - }); + pub fn set_identity(&mut self, ident: Option<&str>) { + self.ident = ident + .and_then(|ident| { + let ident = ident.bytes().chain([0]).collect(); + // SAFETY: Already validated + Some(unsafe { String::from_utf8_unchecked(ident) }) + }) + .unwrap_or_else(|| { + unsafe { CStr::from_nullable_ptr(platform::program_invocation_short_name) } + .and_then(|name| { + let name = name.to_str().ok()?.bytes().chain([0]).collect(); + // SAFETY: Validated above + Some(unsafe { String::from_utf8_unchecked(name) }) + }) + .unwrap_or_else(|| "\0".to_owned()) + }); } /// Open the internal [`LogFile`] if it's not open. @@ -172,3 +201,76 @@ bitflags! { const PError = LOG_PERROR; } } + +bitflags! { + /// Packed Facility-Priority bit field. + #[derive(Clone, Copy)] + pub struct Priority: c_int { + const Emerg = LOG_EMERG; + const Alert = LOG_ALERT; + const Crit = LOG_CRIT; + const Err = LOG_ERR; + const Warn = LOG_WARNING; + const Notice = LOG_NOTICE; + const Info = LOG_INFO; + const Debug = LOG_DEBUG; + + const UpToEmerg = LOG_UPTO(LOG_EMERG); + const UpToAlert = LOG_UPTO(LOG_ALERT); + const UpToCrit = LOG_UPTO(LOG_CRIT); + const UpToErr = LOG_UPTO(LOG_ERR); + const UpToWarn = LOG_UPTO(LOG_WARNING); + const UpToNotice = LOG_UPTO(LOG_NOTICE); + const UpToInfo = LOG_UPTO(LOG_INFO); + const UpToDebug = LOG_UPTO(LOG_DEBUG); + + const Kern = LOG_KERN; + const User = LOG_USER; + const Mail = LOG_MAIL; + const Daemon = LOG_DAEMON; + const Auth = LOG_AUTH; + const Syslog = LOG_SYSLOG; + const Printer = LOG_LPR; + const News = LOG_NEWS; + const UUCP = LOG_UUCP; + const CRON = LOG_CRON; + const AuthPriv = LOG_AUTHPRIV; + const FTP = LOG_FTP; + const Local0 = LOG_LOCAL0; + const Local1 = LOG_LOCAL1; + const Local2 = LOG_LOCAL2; + const Local3 = LOG_LOCAL3; + const Local4 = LOG_LOCAL4; + const Local5 = LOG_LOCAL5; + const Local6 = LOG_LOCAL6; + const Local7 = LOG_LOCAL7; + + // Internal constants for extracting facility or priority from a packed bitfield. + const FacilityMask = 0x3ff; + const PriorityMask = !Self::FacilityMask.bits(); + } +} + +impl Priority { + /// Keep facility but replace severity mask. + pub fn with_mask(self, mask: c_int) -> Option { + // Fail on invalid bits and drop invalid facility bits. + let mask = Self::from_bits(mask)? & Self::FacilityMask; + let facility = self & Self::PriorityMask; + Some(mask | facility) + } + + /// Keep mask but replace facility. + pub fn with_facility(self, facility: c_int) -> Option { + // Fail on invalid bits and drop invalid priority bits. + let facility = Self::from_bits(facility)? & Self::PriorityMask; + let mask = self & Self::FacilityMask; + Some(mask | facility) + } + + /// Returns if a message of `priority` should be retained by this mask. + pub fn should_log(self, priority: Self) -> bool { + (self & Self::FacilityMask) + .contains(Priority::from_bits_truncate(LOG_MASK(priority.bits()))) + } +} diff --git a/src/header/sys_syslog/mod.rs b/src/header/sys_syslog/mod.rs index 9c3025ce8a..a2032a764a 100644 --- a/src/header/sys_syslog/mod.rs +++ b/src/header/sys_syslog/mod.rs @@ -14,21 +14,21 @@ pub mod logger; use core::ffi::VaList; use crate::{c_str::CStr, platform::types::*}; -use logger::LOGGER; +use logger::{Priority, LOGGER}; -// Values for logopt +/// Record the caller's PID in log messages. pub const LOG_PID: c_int = 0x01; +/// Write to /dev/console if [`syslog`] fails. pub const LOG_CONS: c_int = 0x02; +/// Open the log on the first call to [`syslog`] rather than opening it early. +/// This is the default behavior and setting or unsetting this option does nothing. pub const LOG_ODELAY: c_int = 0x04; +/// Open the log file immediately. pub const LOG_NDELAY: c_int = 0x08; pub const LOG_NOWAIT: c_int = 0x10; +/// Print log message to stderr as well as the log. pub const LOG_PERROR: c_int = 0x20; -// Facilities -// Note: in this case I relied more on MUSL than on POSIX1.2017 -// as it appears there were some Linux-specific facilities -// Which could be used by programs we want to port over -// And GNU Libc had these too pub const LOG_KERN: c_int = 0 << 3; pub const LOG_USER: c_int = 1 << 3; pub const LOG_MAIL: c_int = 2 << 3; @@ -41,6 +41,7 @@ pub const LOG_UUCP: c_int = 8 << 3; pub const LOG_CRON: c_int = 9 << 3; pub const LOG_AUTHPRIV: c_int = 10 << 3; pub const LOG_FTP: c_int = 11 << 3; + pub const LOG_LOCAL0: c_int = 16 << 3; pub const LOG_LOCAL1: c_int = 17 << 3; pub const LOG_LOCAL2: c_int = 18 << 3; @@ -61,18 +62,28 @@ pub const LOG_NOTICE: c_int = 5; pub const LOG_INFO: c_int = 6; pub const LOG_DEBUG: c_int = 7; -// Internal constant for extracting facility from a packed facility-priority bitfield. -// TODO: Remove or use a packed i32 like musl. -const LOG_FACMASK: c_int = 0x3f8; +/// Create a mask that includes all levels up to a certain priority. +#[no_mangle] +pub const extern "C" fn LOG_UPTO(p: c_int) -> c_int { + (1 << (p + 1)) - 1 +} + +/// Create a mask that enables a single priority. +#[no_mangle] +pub const extern "C" fn LOG_MASK(p: c_int) -> c_int { + 1 << p +} #[no_mangle] -pub extern "C" fn setlogmask(maskpri: c_int) -> c_int { +pub extern "C" fn setlogmask(mask: c_int) -> c_int { let mut params = LOGGER.lock(); - let ret = params.mask; - if (maskpri != 0) { - params.mask = maskpri; + let old = params.mask.bits(); + if (mask != 0) { + if let Some(mask) = params.mask.with_mask(mask) { + params.mask = mask; + } } - ret + old } #[no_mangle] @@ -83,7 +94,12 @@ pub unsafe extern "C" fn openlog(ident: *const c_char, opt: c_int, facility: c_i let mut params = LOGGER.lock(); params.set_identity_cstr(ident); params.opt = conf; - params.facility = facility; + params.mask = params.mask.with_facility(facility).unwrap_or( + params + .mask + .with_facility(Priority::User.bits()) + .expect("`User` is a valid syslog facility"), + ); // Ensure log is ready to write now instead of checking on the first message. if conf.contains(logger::Config::NoDelay) { @@ -93,11 +109,17 @@ pub unsafe extern "C" fn openlog(ident: *const c_char, opt: c_int, facility: c_i #[no_mangle] pub unsafe extern "C" fn vsyslog(priority: c_int, message: *const c_char, mut ap: VaList) { - let mut logger = LOGGER.lock(); - if (((logger.mask & (1 << (priority & 7))) == 0) || ((priority & !0x3ff) != 0)) { + let Some(message) = CStr::from_nullable_ptr(message) else { return; }; - logger.write_log(priority, message, ap); + let Some(priority) = Priority::from_bits(priority) else { + return; + }; + + let mut logger = LOGGER.lock(); + if logger.mask.should_log(priority) { + logger.write_log(priority, message, ap); + } } #[no_mangle] diff --git a/tests/Makefile b/tests/Makefile index b1c7d3dc1e..89a0aa6c75 100644 --- a/tests/Makefile +++ b/tests/Makefile @@ -97,6 +97,7 @@ EXPECT_NAMES=\ string/stpncpy \ strings \ sys_mman \ + sys_syslog/syslog \ time/asctime \ time/constants \ time/gmtime \ @@ -162,10 +163,6 @@ EXPECT_NAMES=\ # TODO: Fix these # netdb/netdb \ -ifeq ($(REDOX_TESTS),1) - EXPECT_NAMES+=syslog/syslog -endif - BUILD?=. DYNAMIC_ONLY_NAMES=\ diff --git a/tests/expected/bins_dynamic/sys_syslog.stderr b/tests/expected/bins_dynamic/sys_syslog.stderr new file mode 100644 index 0000000000..faddade2a6 --- /dev/null +++ b/tests/expected/bins_dynamic/sys_syslog.stderr @@ -0,0 +1,13 @@ +relibc_test: This is a test message with formatting: 5 +relibc_test: Hank Hill +relibc_test: Foo has been bar'd +relibc_test: And now, Eeveelutions +relibc_test: Espeon +relibc_test: Umbreon +relibc_test: Sylveon +relibc_test: Glaceon +relibc_test: Leafeon +relibc_test: Vaporeon +relibc_test: Flareon +relibc_test: Jolteon +relibc_test: Bye from relibc's syslog tests! diff --git a/tests/expected/bins_dynamic/sys_syslog.stdout b/tests/expected/bins_dynamic/sys_syslog.stdout new file mode 100644 index 0000000000..e69de29bb2 diff --git a/tests/expected/bins_static/sys_syslog.stderr b/tests/expected/bins_static/sys_syslog.stderr new file mode 100644 index 0000000000..faddade2a6 --- /dev/null +++ b/tests/expected/bins_static/sys_syslog.stderr @@ -0,0 +1,13 @@ +relibc_test: This is a test message with formatting: 5 +relibc_test: Hank Hill +relibc_test: Foo has been bar'd +relibc_test: And now, Eeveelutions +relibc_test: Espeon +relibc_test: Umbreon +relibc_test: Sylveon +relibc_test: Glaceon +relibc_test: Leafeon +relibc_test: Vaporeon +relibc_test: Flareon +relibc_test: Jolteon +relibc_test: Bye from relibc's syslog tests! diff --git a/tests/expected/bins_static/sys_syslog.stdout b/tests/expected/bins_static/sys_syslog.stdout new file mode 100644 index 0000000000..e69de29bb2 diff --git a/tests/sys_syslog/syslog.c b/tests/sys_syslog/syslog.c new file mode 100644 index 0000000000..f7a5a2e75a --- /dev/null +++ b/tests/sys_syslog/syslog.c @@ -0,0 +1,46 @@ +#include +#include + +int main(void) { + // Test that syslog succeeds without explicitly calling openlog + syslog(LOG_INFO, "Testing syslog; disregard"); + closelog(); + + // The rest of the tests use LOG_PERROR so we get verifiable output on stderr + openlog("relibc_test", + LOG_CONS | LOG_PERROR | LOG_NDELAY, + LOG_LOCAL2 + ); + + // Basic + syslog(LOG_EMERG, "This is a test message with formatting: %d", 5); + + // Only alert should print + setlogmask(LOG_MASK(LOG_ALERT)); + syslog(LOG_ALERT, "Hank Hill"); + syslog(LOG_EMERG, "Sells propane and propane accessories"); + + // Squelch all logs with a priority less than WARNING. + setlogmask(LOG_UPTO(LOG_WARNING)); + // First line should be emitted while the second shouldn't. + syslog(LOG_WARNING, "Foo has been bar'd"); + syslog(LOG_NOTICE, "I am a very spammy log message. Ha!"); + + // All of these should print + setlogmask(LOG_UPTO(LOG_DEBUG)); + syslog(LOG_DEBUG, "And now, Eeveelutions"); + syslog(LOG_DEBUG, "Espeon"); + syslog(LOG_INFO, "Umbreon"); + syslog(LOG_NOTICE, "Sylveon"); + syslog(LOG_WARNING, "Glaceon"); + syslog(LOG_ERR, "Leafeon"); + syslog(LOG_CRIT, "Vaporeon"); + syslog(LOG_ALERT, "Flareon"); + syslog(LOG_EMERG, "Jolteon"); + + // The log file should automatically open even if closed. + closelog(); + syslog(LOG_INFO, "Bye from relibc's syslog tests!"); + + return EXIT_SUCCESS; +} diff --git a/tests/syslog/syslog.c b/tests/syslog/syslog.c deleted file mode 100644 index e4e9d80d06..0000000000 --- a/tests/syslog/syslog.c +++ /dev/null @@ -1,29 +0,0 @@ -#include -#include - -int main(void) { - // Test that syslog succeeds without explicitly calling openlog - syslog(LOG_INFO, "Testing syslog; disregard"); - closelog(); - - // The rest of the tests use LOG_PERROR so we get verifiable output on stderr - openlog("relibc_test", - LOG_CONS | LOG_PERROR | LOG_NDELAY, - LOG_LOCAL2 - ); - - // Basic - syslog(LOG_EMERG, "This is a test message with extra: %d", 5); - - // (This isn't available in Redox yet) - // Squelch all logs with a priority less than WARNING. - // setlogmask(LOG_UPTO(LOG_WARNING)); - - // First line should be emitted while the second shouldn't. - syslog(LOG_WARNING, "Foo has been bar'd"); - syslog(LOG_NOTICE, "I am a very spammy log message. Ha!"); - - // TODO: LOG_MASK after implemented - - return EXIT_SUCCESS; -}