diff --git a/ffi/firewood.go b/ffi/firewood.go index 222a81ce4f..5c348b7b8a 100644 --- a/ffi/firewood.go +++ b/ffi/firewood.go @@ -92,8 +92,14 @@ type config struct { revisions uint // readCacheStrategy is the caching strategy used for the node cache. readCacheStrategy CacheStrategy - // rootStore defines whether to enable storing all historical revisions on disk. - rootStore bool + // rootStore defines whether to enable storing all historical revisions on disk. + rootStore bool + // logPath is the file path where logs will be written. + // If empty, logging is disabled. + logPath string + // logFilter is the RUST_LOG format filter string for logging. + // If empty and logPath is set, env_logger defaults will be used. + logFilter string } func defaultConfig() *config { @@ -160,8 +166,30 @@ func WithReadCacheStrategy(strategy CacheStrategy) Option { // removed from memory (based on the Revisions limit). // Default: false func WithRootStore() Option { +// is already initialized (e.g., by a previous call to New with WithLogPath), +// subsequent calls will fail with an error. +// +// The logger is initialized before opening the database. If database opening fails, +// the logger remains initialized and subsequent New calls with WithLogPath will fail. +// +// Use "/dev/stdout" to write logs to standard output. +// Default: empty string (logging disabled) +func WithLogPath(path string) Option { return func(c *config) { - c.rootStore = true + c.logPath = path + } +} + +// WithLogFilter sets the filter string for logging using RUST_LOG format. +// Common usage: "info" to show info-level and above logs. +// See env_logger documentation for full RUST_LOG format: https://docs.rs/env_logger +// +// This option only takes effect when WithLogPath is also set. +// If empty and WithLogPath is set, env_logger defaults will be used. +// Default: empty string +func WithLogFilter(filter string) Option { + return func(c *config) { + c.logFilter = filter } } @@ -210,6 +238,24 @@ func New(dbDir string, opts ...Option) (*Database, error) { return nil, fmt.Errorf("free list cache entries must be >= 1, got %d", conf.freeListCacheEntries) } + // Initialize logging if logPath is set. + // Logging is global per-process and must be initialized before opening the database. + // If initialization fails, return error immediately without attempting to open database. + // If database opening subsequently fails, the logger remains initialized. + if conf.logPath != "" { + var pinner runtime.Pinner + defer pinner.Unpin() + + logArgs := C.struct_LogArgs{ + path: newBorrowedBytes([]byte(conf.logPath), &pinner), + filter_level: newBorrowedBytes([]byte(conf.logFilter), &pinner), + } + + if err := getErrorFromVoidResult(C.fwd_start_logs(logArgs)); err != nil { + return nil, fmt.Errorf("failed to initialize logging: %w", err) + } + } + var pinner runtime.Pinner defer pinner.Unpin() diff --git a/ffi/firewood.h b/ffi/firewood.h index 9e182df882..70d6abe968 100644 --- a/ffi/firewood.h +++ b/ffi/firewood.h @@ -1013,15 +1013,17 @@ typedef struct LogArgs { /** * The file path where logs for this process are stored. * - * If empty, this is set to `${TMPDIR}/firewood-log.txt`. + * This is required and must not be empty. Use "/dev/stdout" for stdout logging. * * This is required to be a valid UTF-8 string. */ BorrowedBytes path; /** - * The filter level for logs. + * The filter string in `RUST_LOG` format. * - * If empty, this is set to `info`. + * If empty, `env_logger` defaults will be used. + * Common example: "info" to show info-level and above logs. + * See for full `RUST_LOG` format documentation. * * This is required to be a valid UTF-8 string. */ @@ -2030,14 +2032,18 @@ struct HashResult fwd_root_hash(const struct DatabaseHandle *db); /** * Start logs for this process. * + * Logging is global per-process and can only be initialized once. Subsequent calls + * will return an error. + * * # Arguments * * See [`LogArgs`]. * * # Returns * - * - [`VoidResult::Ok`] if the recorder was initialized. - * - [`VoidResult::Err`] if an error occurs during initialization. + * - [`VoidResult::Ok`] if the logger was initialized. + * - [`VoidResult::Err`] if an error occurs during initialization (e.g., invalid path, + * invalid filter, or logger already initialized). * * # Safety * diff --git a/ffi/firewood_test.go b/ffi/firewood_test.go index 1bd2d112bc..62d53d7f26 100644 --- a/ffi/firewood_test.go +++ b/ffi/firewood_test.go @@ -1571,6 +1571,99 @@ func TestDump(t *testing.T) { } } +// TestLogging tests the WithLogPath and WithLogFilter options. +// This test expects that no other tests in the package initialize logging. +// Tests are run in order: error cases first, then success case, then logger-already-initialized error. +func TestLogging(t *testing.T) { + ctx := t.Context() + + // Test 1: Empty log path should not initialize logging (no error) + t.Run("EmptyLogPath", func(t *testing.T) { + r := require.New(t) + dbPath := filepath.Join(t.TempDir(), "test.db") + db, err := New(dbPath, + WithTruncate(true), + WithLogPath(""), + ) + // Empty path means logging is disabled, should succeed + r.NoError(err) + r.NotNil(db) + defer func() { + ctx, cancel := context.WithTimeout(context.Background(), time.Second) + defer cancel() + r.NoError(db.Close(ctx)) + }() + }) + + // Test 2: Invalid log path should fail + t.Run("InvalidLogPath", func(t *testing.T) { + r := require.New(t) + dbPath := filepath.Join(t.TempDir(), "test.db") + // Use a path that cannot be created (e.g., parent is a file) + invalidLogDir := filepath.Join(t.TempDir(), "file_not_dir") + r.NoError(os.WriteFile(invalidLogDir, []byte("not a directory"), 0o644)) + invalidLogPath := filepath.Join(invalidLogDir, "subdir", "test.log") + + db, err := New(dbPath, + WithTruncate(true), + WithLogPath(invalidLogPath), + WithLogFilter("trace"), + ) + r.Error(err) + r.Nil(db) + r.Contains(err.Error(), "failed to initialize logging") + }) + + // Test 3: Success case - valid log path with trace filter + t.Run("ValidLogging", func(t *testing.T) { + r := require.New(t) + dbPath := filepath.Join(t.TempDir(), "test.db") + logPath := filepath.Join(t.TempDir(), "firewood.log") + + db, err := New(dbPath, + WithTruncate(true), + WithLogPath(logPath), + WithLogFilter("trace"), + ) + r.NoError(err) + r.NotNil(db) + defer func() { + ctx, cancel := context.WithTimeout(ctx, time.Second) + defer cancel() + r.NoError(db.Close(ctx)) + }() + + // Perform some operations to generate logs + keys := [][]byte{[]byte("key1")} + vals := [][]byte{[]byte("value1")} + _, err = db.Update(keys, vals) + r.NoError(err) + + // Verify log file was created and contains trace logs + logContents, err := os.ReadFile(logPath) + r.NoError(err) + r.NotEmpty(logContents, "log file should contain trace logs from database opening") + + // Verify the log contains our trace message from opening + r.Contains(string(logContents), "Opening Firewood database") + }) + + // Test 4: Logger already initialized error + t.Run("LoggerAlreadyInitialized", func(t *testing.T) { + r := require.New(t) + dbPath := filepath.Join(t.TempDir(), "test2.db") + logPath := filepath.Join(t.TempDir(), "firewood2.log") + + db, err := New(dbPath, + WithTruncate(true), + WithLogPath(logPath), + WithLogFilter("info"), + ) + r.Error(err) + r.Nil(db) + r.Contains(err.Error(), "failed to initialize logging") + r.Contains(err.Error(), "attempted to set a logger after the logging system was already initialized") + }) var block_307_items string = ` d20628954718b36081ad06b1a04fb8896f3090eb5c7ab3cd9086e50e61d88b7eb10e2d527612073b26eecdfd717e6a320cf44b4afac2b0732d9fcbe2b7fa0cf6:944abef613822fb2031d897e792f89c896ddafc466 d20628954718b36081ad06b1a04fb8896f3090eb5c7ab3cd9086e50e61d88b7e:f8450180a00000000000000000000000000000000000000000000000000000000000000000a0a33ec8100b06cfbacc612bc2baa4d36f01d5d52df97bcef04f54d5b8ceccbd9280 diff --git a/ffi/metrics.go b/ffi/metrics.go index e50ae69b58..6c4223fc2e 100644 --- a/ffi/metrics.go +++ b/ffi/metrics.go @@ -10,7 +10,6 @@ package ffi import "C" import ( - "runtime" "strings" "github.com/prometheus/client_golang/prometheus" @@ -73,24 +72,3 @@ func GatherMetrics() (string, error) { return string(bytes), nil } - -// LogConfig configures logs for this process. -type LogConfig struct { - Path string - FilterLevel string -} - -// Starts global logs. -// This function only needs to be called once. -// An error is returned if this method is called a second time. -func StartLogs(config *LogConfig) error { - var pinner runtime.Pinner - defer pinner.Unpin() - - args := C.struct_LogArgs{ - path: newBorrowedBytes([]byte(config.Path), &pinner), - filter_level: newBorrowedBytes([]byte(config.FilterLevel), &pinner), - } - - return getErrorFromVoidResult(C.fwd_start_logs(args)) -} diff --git a/ffi/metrics_test.go b/ffi/metrics_test.go index b588ee2d4a..e3495d41cb 100644 --- a/ffi/metrics_test.go +++ b/ffi/metrics_test.go @@ -7,8 +7,6 @@ import ( "fmt" "io" "net/http" - "os" - "path/filepath" "testing" "time" @@ -25,24 +23,12 @@ func TestMetrics(t *testing.T) { // test params var ( - logPath = filepath.Join(t.TempDir(), "firewood.log") metricsPort = uint16(3000) ) db := newTestDatabase(t) r.NoError(StartMetricsWithExporter(metricsPort)) - logConfig := &LogConfig{ - Path: logPath, - FilterLevel: "trace", - } - - var logsDisabled bool - if err := StartLogs(logConfig); err != nil { - r.Contains(err.Error(), "Logging is not available") - logsDisabled = true - } - // Populate DB keys, vals := kvForTest(10) _, err := db.Update(keys, vals) @@ -93,11 +79,4 @@ func TestMetrics(t *testing.T) { r.NotNil(d) r.Equal(v, *d.Type) } - - if !logsDisabled { - // logs should be non-empty if logging with trace filter level - f, err := os.ReadFile(logPath) - r.NoError(err) - r.NotEmpty(f) - } } diff --git a/ffi/src/lib.rs b/ffi/src/lib.rs index 2577451ce8..2a44c44cef 100644 --- a/ffi/src/lib.rs +++ b/ffi/src/lib.rs @@ -659,14 +659,18 @@ pub unsafe extern "C" fn fwd_open_db(args: DatabaseHandleArgs) -> HandleResult { /// Start logs for this process. /// +/// Logging is global per-process and can only be initialized once. Subsequent calls +/// will return an error. +/// /// # Arguments /// /// See [`LogArgs`]. /// /// # Returns /// -/// - [`VoidResult::Ok`] if the recorder was initialized. -/// - [`VoidResult::Err`] if an error occurs during initialization. +/// - [`VoidResult::Ok`] if the logger was initialized. +/// - [`VoidResult::Err`] if an error occurs during initialization (e.g., invalid path, +/// invalid filter, or logger already initialized). /// /// # Safety /// diff --git a/ffi/src/logging.rs b/ffi/src/logging.rs index 8392357425..ad521d55ea 100644 --- a/ffi/src/logging.rs +++ b/ffi/src/logging.rs @@ -9,14 +9,16 @@ use crate::BorrowedBytes; pub struct LogArgs<'a> { /// The file path where logs for this process are stored. /// - /// If empty, this is set to `${TMPDIR}/firewood-log.txt`. + /// This is required and must not be empty. Use "/dev/stdout" for stdout logging. /// /// This is required to be a valid UTF-8 string. pub path: BorrowedBytes<'a>, - /// The filter level for logs. + /// The filter string in `RUST_LOG` format. /// - /// If empty, this is set to `info`. + /// If empty, `env_logger` defaults will be used. + /// Common example: "info" to show info-level and above logs. + /// See for full `RUST_LOG` format documentation. /// /// This is required to be a valid UTF-8 string. pub filter_level: BorrowedBytes<'a>, @@ -24,7 +26,7 @@ pub struct LogArgs<'a> { #[cfg(feature = "logger")] impl LogArgs<'_> { - fn path(&self) -> std::io::Result> { + fn path(&self) -> std::io::Result<&std::path::Path> { let path = self.path.as_str().map_err(|err| { std::io::Error::new( std::io::ErrorKind::InvalidInput, @@ -32,34 +34,33 @@ impl LogArgs<'_> { ) })?; if path.is_empty() { - Ok(std::borrow::Cow::Owned( - std::env::temp_dir().join("firewood-log.txt"), - )) - } else { - Ok(std::borrow::Cow::Borrowed(std::path::Path::new(path))) + return Err(std::io::Error::new( + std::io::ErrorKind::InvalidInput, + "log path must not be empty", + )); } + Ok(std::path::Path::new(path)) } - fn log_level(&self) -> std::io::Result<&str> { - let level = self.filter_level.as_str().map_err(|err| { + fn log_filter(&self) -> std::io::Result<&str> { + let filter = self.filter_level.as_str().map_err(|err| { std::io::Error::new( std::io::ErrorKind::InvalidInput, - format!("log level contains invalid utf-8: {err}"), + format!("log filter contains invalid utf-8: {err}"), ) })?; - if level.is_empty() { - Ok("info") - } else { - Ok(level) - } + Ok(filter) } - /// Starts logging to the specified file path with the given filter level. + /// Starts logging to the specified file path with the given filter. + /// + /// The filter uses `RUST_LOG` format. See `env_logger` documentation for details. + /// Logging is global per-process and can only be initialized once. /// /// # Errors /// - /// If the log file cannot be created or opened, or if the log level is invalid, - /// this will return an error. + /// If the log file cannot be created or opened, if the log filter is invalid, + /// or if the logger has already been initialized, this will return an error. pub fn start_logging(&self) -> std::io::Result<()> { use env_logger::Target::Pipe; use std::fs::OpenOptions; @@ -78,19 +79,12 @@ impl LogArgs<'_> { })?; } - let level = self.log_level()?; - let level = level.parse().map_err(|e| { - std::io::Error::new( - std::io::ErrorKind::InvalidInput, - format!("invalid log level `{level}`: {e}"), - ) - })?; + let filter = self.log_filter()?; let file = OpenOptions::new() .create(true) - .write(true) - .truncate(false) - .open(&log_path) + .append(true) + .open(log_path) .map_err(|e| { std::io::Error::new( e.kind(), @@ -98,9 +92,14 @@ impl LogArgs<'_> { ) })?; - env_logger::Builder::new() - .filter_level(level) - .target(Pipe(Box::new(file))) + let mut builder = env_logger::Builder::new(); + builder.target(Pipe(Box::new(file))); + + if !filter.is_empty() { + builder.parse_filters(filter); + } + + builder .try_init() .map_err(|e| std::io::Error::other(format!("failed to initialize logger: {e}")))?; diff --git a/firewood/src/db.rs b/firewood/src/db.rs index 0416591ca7..3265145fda 100644 --- a/firewood/src/db.rs +++ b/firewood/src/db.rs @@ -18,6 +18,7 @@ use crate::v2::api::{ }; use crate::manager::{ConfigManager, RevisionManager, RevisionManagerConfig}; +use firewood_storage::logger::trace; use firewood_storage::{ CheckOpt, CheckerReport, Committed, FileBacked, FileIoError, HashedNodeReader, ImmutableProposal, NodeStore, Parentable, ReadableStorage, TrieReader, @@ -167,6 +168,10 @@ impl api::Db for Db { impl Db { /// Create a new database instance. pub fn new>(db_dir: P, cfg: DbConfig) -> Result { + trace!( + "Opening Firewood database at path: {}", + db_dir.as_ref().display() + ); let metrics = Arc::new(DbMetrics { proposals: counter!("firewood.proposals"), });