Browse Source

feat: log to file (#967)

thesimplekid 1 tháng trước cách đây
mục cha
commit
761ed82554

+ 1 - 0
Cargo.toml

@@ -75,6 +75,7 @@ tokio-tungstenite = { version = "0.26.0", default-features = false }
 tokio-stream = "0.1.15"
 tracing = { version = "0.1", default-features = false, features = ["attributes", "log"] }
 tracing-subscriber = { version = "0.3.18", features = ["env-filter"] }
+tracing-appender = "0.2"
 url = "2.3"
 uuid = { version = "1.17", features = ["v4", "serde"] }
 utoipa = { version = "5.3.1", features = [

+ 15 - 0
crates/cdk-integration-tests/src/shared.rs

@@ -168,6 +168,11 @@ pub fn create_fake_wallet_settings(
                 .map(|(_, certs_dir)| certs_dir.clone()),
             input_fee_ppk: None,
             http_cache: cache::Config::default(),
+            logging: cdk_mintd::config::LoggingConfig {
+                output: cdk_mintd::config::LoggingOutput::Both,
+                console_level: Some("debug".to_string()),
+                file_level: Some("debug".to_string()),
+            },
             enable_swagger_ui: None,
         },
         mint_info: cdk_mintd::config::MintInfo::default(),
@@ -210,6 +215,11 @@ pub fn create_cln_settings(
             signatory_certs: None,
             input_fee_ppk: None,
             http_cache: cache::Config::default(),
+            logging: cdk_mintd::config::LoggingConfig {
+                output: cdk_mintd::config::LoggingOutput::Both,
+                console_level: Some("debug".to_string()),
+                file_level: Some("debug".to_string()),
+            },
             enable_swagger_ui: None,
         },
         mint_info: cdk_mintd::config::MintInfo::default(),
@@ -248,6 +258,11 @@ pub fn create_lnd_settings(
             signatory_certs: None,
             input_fee_ppk: None,
             http_cache: cache::Config::default(),
+            logging: cdk_mintd::config::LoggingConfig {
+                output: cdk_mintd::config::LoggingOutput::Both,
+                console_level: Some("debug".to_string()),
+                file_level: Some("debug".to_string()),
+            },
             enable_swagger_ui: None,
         },
         mint_info: cdk_mintd::config::MintInfo::default(),

+ 1 - 0
crates/cdk-mintd/Cargo.toml

@@ -50,6 +50,7 @@ bitcoin.workspace = true
 tokio = { workspace = true, default-features = false, features = ["signal"] }
 tracing.workspace = true
 tracing-subscriber.workspace = true
+tracing-appender.workspace = true
 futures.workspace = true
 serde.workspace = true
 bip39.workspace = true

+ 56 - 0
crates/cdk-mintd/README.md

@@ -87,6 +87,60 @@ engine = "redb"
 ln_backend = "fakewallet"  # Options: cln, lnd, lnbits, fakewallet
 ```
 
+### Logging Configuration
+
+You can configure where mintd outputs its logs using the `[info.logging]` section in your config file or environment variables:
+
+**Config file:**
+```toml
+[info.logging]
+# Where to output logs: "stdout", "file", or "both" (default: "both")
+output = "both"
+# Log level for console output (default: "info")
+console_level = "info"  
+# Log level for file output (default: "debug")
+file_level = "debug"
+```
+
+**Environment variables:**
+```bash
+# Where to output logs: "stdout", "file", or "both" (default: "both")
+export CDK_MINTD_LOGGING_OUTPUT="both"
+# Log level for console output (default: "info")
+export CDK_MINTD_LOGGING_CONSOLE_LEVEL="debug"
+# Log level for file output (default: "debug")
+export CDK_MINTD_LOGGING_FILE_LEVEL="debug"
+```
+
+**Available logging outputs:**
+- `"stdout"` - Output logs only to console/terminal (stderr)
+- `"file"` - Output logs only to rotating daily log files in `<work_dir>/logs/`
+- `"both"` - Output logs to both console and files (default behavior)
+
+**Available log levels:** `error`, `warn`, `info`, `debug`, `trace`
+
+**Examples:**
+
+Console only with debug level:
+```bash
+export CDK_MINTD_LOGGING_OUTPUT="stdout"
+export CDK_MINTD_LOGGING_CONSOLE_LEVEL="debug"
+```
+
+File only with debug level:
+```toml
+[info.logging]
+output = "file"
+file_level = "debug"
+```
+
+Both console (warn) and file (debug):
+```bash
+export CDK_MINTD_LOGGING_OUTPUT="both"
+export CDK_MINTD_LOGGING_CONSOLE_LEVEL="warn"
+export CDK_MINTD_LOGGING_FILE_LEVEL="debug"
+```
+
 ## Usage
 
 ```bash
@@ -98,6 +152,8 @@ cdk-mintd --config /path/to/config.toml
 
 # Start with specific work directory
 cdk-mintd --work-dir /path/to/work/dir
+# Disable logging entirely
+cdk-mintd --enable-logging false
 
 # Show help
 cdk-mintd --help

+ 9 - 0
crates/cdk-mintd/example.config.toml

@@ -6,6 +6,15 @@ mnemonic = ""
 # input_fee_ppk = 0
 # enable_swagger_ui = false
 
+[info.logging]
+# Where to output logs: "stdout", "file", or "both" (default: "both")
+# Note: "stdout" actually outputs to stderr (standard error stream)
+# output = "both"
+# Log level for console output (default: "info")
+# console_level = "info"  
+# Log level for file output (default: "debug")
+# file_level = "debug"
+
 [mint_management_rpc]
 enabled = false
 # address = "127.0.0.1"

+ 86 - 0
crates/cdk-mintd/src/config.rs

@@ -7,6 +7,44 @@ use cdk_axum::cache;
 use config::{Config, ConfigError, File};
 use serde::{Deserialize, Serialize};
 
+#[derive(Debug, Serialize, Deserialize, Clone, PartialEq, Default)]
+#[serde(rename_all = "lowercase")]
+pub enum LoggingOutput {
+    /// Log to stderr only
+    Stderr,
+    /// Log to file only
+    File,
+    /// Log to both stderr and file (default)
+    #[default]
+    Both,
+}
+
+impl std::str::FromStr for LoggingOutput {
+    type Err = String;
+
+    fn from_str(s: &str) -> Result<Self, Self::Err> {
+        match s.to_lowercase().as_str() {
+            "stderr" => Ok(LoggingOutput::Stderr),
+            "file" => Ok(LoggingOutput::File),
+            "both" => Ok(LoggingOutput::Both),
+            _ => Err(format!(
+                "Unknown logging output: {s}. Valid options: stdout, file, both"
+            )),
+        }
+    }
+}
+
+#[derive(Debug, Clone, Serialize, Deserialize, Default)]
+pub struct LoggingConfig {
+    /// Where to output logs: stdout, file, or both
+    #[serde(default)]
+    pub output: LoggingOutput,
+    /// Log level for console output (when stdout or both)
+    pub console_level: Option<String>,
+    /// Log level for file output (when file or both)
+    pub file_level: Option<String>,
+}
+
 #[derive(Clone, Serialize, Deserialize, Default)]
 pub struct Info {
     pub url: String,
@@ -19,6 +57,10 @@ pub struct Info {
 
     pub http_cache: cache::Config,
 
+    /// Logging configuration
+    #[serde(default)]
+    pub logging: LoggingConfig,
+
     /// When this is set to true, the mint exposes a Swagger UI for it's API at
     /// `[listen_host]:[listen_port]/swagger-ui`
     ///
@@ -45,6 +87,7 @@ impl std::fmt::Debug for Info {
             .field("mnemonic", &mnemonic_display)
             .field("input_fee_ppk", &self.input_fee_ppk)
             .field("http_cache", &self.http_cache)
+            .field("logging", &self.logging)
             .field("enable_swagger_ui", &self.enable_swagger_ui)
             .finish()
     }
@@ -422,6 +465,8 @@ impl Settings {
 #[cfg(test)]
 mod tests {
 
+    use std::str::FromStr;
+
     use super::*;
 
     #[test]
@@ -488,4 +533,45 @@ mod tests {
         assert!(!debug_output.contains("特殊字符 !@#$%^&*()"));
         assert!(debug_output.contains("<hashed: "));
     }
+
+    #[test]
+    fn test_logging_output_from_str() {
+        assert_eq!(
+            LoggingOutput::from_str("stderr").unwrap(),
+            LoggingOutput::Stderr
+        );
+        assert_eq!(
+            LoggingOutput::from_str("file").unwrap(),
+            LoggingOutput::File
+        );
+        assert_eq!(
+            LoggingOutput::from_str("both").unwrap(),
+            LoggingOutput::Both
+        );
+
+        // Test case insensitive
+        assert_eq!(
+            LoggingOutput::from_str("STDERR").unwrap(),
+            LoggingOutput::Stderr
+        );
+        assert_eq!(
+            LoggingOutput::from_str("File").unwrap(),
+            LoggingOutput::File
+        );
+        assert_eq!(
+            LoggingOutput::from_str("BOTH").unwrap(),
+            LoggingOutput::Both
+        );
+
+        // Test invalid input
+        assert!(LoggingOutput::from_str("invalid").is_err());
+    }
+
+    #[test]
+    fn test_logging_config_defaults() {
+        let config = LoggingConfig::default();
+        assert_eq!(config.output, LoggingOutput::Both);
+        assert_eq!(config.console_level, None);
+        assert_eq!(config.file_level, None);
+    }
 }

+ 3 - 0
crates/cdk-mintd/src/env_vars/common.rs

@@ -14,3 +14,6 @@ pub const ENV_CACHE_SECONDS: &str = "CDK_MINTD_CACHE_SECONDS";
 pub const ENV_EXTEND_CACHE_SECONDS: &str = "CDK_MINTD_EXTEND_CACHE_SECONDS";
 pub const ENV_INPUT_FEE_PPK: &str = "CDK_MINTD_INPUT_FEE_PPK";
 pub const ENV_ENABLE_SWAGGER: &str = "CDK_MINTD_ENABLE_SWAGGER";
+pub const ENV_LOGGING_OUTPUT: &str = "CDK_MINTD_LOGGING_OUTPUT";
+pub const ENV_LOGGING_CONSOLE_LEVEL: &str = "CDK_MINTD_LOGGING_CONSOLE_LEVEL";
+pub const ENV_LOGGING_FILE_LEVEL: &str = "CDK_MINTD_LOGGING_FILE_LEVEL";

+ 22 - 1
crates/cdk-mintd/src/env_vars/info.rs

@@ -1,9 +1,10 @@
 //! Info environment variables
 
 use std::env;
+use std::str::FromStr;
 
 use super::common::*;
-use crate::config::Info;
+use crate::config::{Info, LoggingOutput};
 
 impl Info {
     pub fn from_env(mut self) -> Self {
@@ -58,6 +59,26 @@ impl Info {
             }
         }
 
+        // Logging configuration
+        if let Ok(output_str) = env::var(ENV_LOGGING_OUTPUT) {
+            if let Ok(output) = LoggingOutput::from_str(&output_str) {
+                self.logging.output = output;
+            } else {
+                tracing::warn!(
+                    "Invalid logging output '{}' in environment variable. Valid options: stdout, file, both",
+                    output_str
+                );
+            }
+        }
+
+        if let Ok(console_level) = env::var(ENV_LOGGING_CONSOLE_LEVEL) {
+            self.logging.console_level = Some(console_level);
+        }
+
+        if let Ok(file_level) = env::var(ENV_LOGGING_FILE_LEVEL) {
+            self.logging.file_level = Some(file_level);
+        }
+
         self.http_cache = self.http_cache.from_env();
 
         self

+ 131 - 16
crates/cdk-mintd/src/lib.rs

@@ -51,6 +51,8 @@ use tower::ServiceBuilder;
 use tower_http::compression::CompressionLayer;
 use tower_http::decompression::RequestDecompressionLayer;
 use tower_http::trace::TraceLayer;
+use tracing_appender::{non_blocking, rolling};
+use tracing_subscriber::fmt::writer::MakeWriterExt;
 use tracing_subscriber::EnvFilter;
 #[cfg(feature = "swagger")]
 use utoipa::OpenApi;
@@ -94,7 +96,12 @@ async fn initial_setup(
 }
 
 /// Sets up and initializes a tracing subscriber with custom log filtering.
-pub fn setup_tracing() {
+/// Logs can be configured to output to stdout only, file only, or both.
+/// Returns a guard that must be kept alive and properly dropped on shutdown.
+pub fn setup_tracing(
+    work_dir: &Path,
+    logging_config: &config::LoggingConfig,
+) -> Result<Option<tracing_appender::non_blocking::WorkerGuard>> {
     let default_filter = "debug";
     let hyper_filter = "hyper=warn";
     let h2_filter = "h2=warn";
@@ -104,7 +111,99 @@ pub fn setup_tracing() {
         "{default_filter},{hyper_filter},{h2_filter},{tower_http}"
     ));
 
-    tracing_subscriber::fmt().with_env_filter(env_filter).init();
+    use config::LoggingOutput;
+    match logging_config.output {
+        LoggingOutput::Stderr => {
+            // Console output only (stderr)
+            let console_level = logging_config
+                .console_level
+                .as_deref()
+                .unwrap_or("info")
+                .parse::<tracing::Level>()
+                .unwrap_or(tracing::Level::INFO);
+
+            let stderr = std::io::stderr.with_max_level(console_level);
+
+            tracing_subscriber::fmt()
+                .with_env_filter(env_filter)
+                .with_writer(stderr)
+                .init();
+
+            tracing::info!("Logging initialized: console only ({}+)", console_level);
+            Ok(None)
+        }
+        LoggingOutput::File => {
+            // File output only
+            let file_level = logging_config
+                .file_level
+                .as_deref()
+                .unwrap_or("debug")
+                .parse::<tracing::Level>()
+                .unwrap_or(tracing::Level::DEBUG);
+
+            // Create logs directory in work_dir if it doesn't exist
+            let logs_dir = work_dir.join("logs");
+            std::fs::create_dir_all(&logs_dir)?;
+
+            // Set up file appender with daily rotation
+            let file_appender = rolling::daily(&logs_dir, "cdk-mintd.log");
+            let (non_blocking_appender, guard) = non_blocking(file_appender);
+
+            let file_writer = non_blocking_appender.with_max_level(file_level);
+
+            tracing_subscriber::fmt()
+                .with_env_filter(env_filter)
+                .with_writer(file_writer)
+                .init();
+
+            tracing::info!(
+                "Logging initialized: file only at {}/cdk-mintd.log ({}+)",
+                logs_dir.display(),
+                file_level
+            );
+            Ok(Some(guard))
+        }
+        LoggingOutput::Both => {
+            // Both console and file output (stderr + file)
+            let console_level = logging_config
+                .console_level
+                .as_deref()
+                .unwrap_or("info")
+                .parse::<tracing::Level>()
+                .unwrap_or(tracing::Level::INFO);
+            let file_level = logging_config
+                .file_level
+                .as_deref()
+                .unwrap_or("debug")
+                .parse::<tracing::Level>()
+                .unwrap_or(tracing::Level::DEBUG);
+
+            // Create logs directory in work_dir if it doesn't exist
+            let logs_dir = work_dir.join("logs");
+            std::fs::create_dir_all(&logs_dir)?;
+
+            // Set up file appender with daily rotation
+            let file_appender = rolling::daily(&logs_dir, "cdk-mintd.log");
+            let (non_blocking_appender, guard) = non_blocking(file_appender);
+
+            // Combine console output (stderr) and file output
+            let stderr = std::io::stderr.with_max_level(console_level);
+            let file_writer = non_blocking_appender.with_max_level(file_level);
+
+            tracing_subscriber::fmt()
+                .with_env_filter(env_filter)
+                .with_writer(stderr.and(file_writer))
+                .init();
+
+            tracing::info!(
+                "Logging initialized: console ({}+) and file at {}/cdk-mintd.log ({}+)",
+                console_level,
+                logs_dir.display(),
+                file_level
+            );
+            Ok(Some(guard))
+        }
+    }
 }
 
 /// Retrieves the work directory based on command-line arguments, environment variables, or system defaults.
@@ -705,7 +804,7 @@ async fn start_services_with_shutdown(
             tracing::info!("Mint info already set, not using config file settings.");
         }
     } else {
-        tracing::warn!("RPC not enabled, using mint info from config.");
+        tracing::info!("RPC not enabled, using mint info from config.");
         mint.set_mint_info(mint_builder_info).await?;
         mint.set_quote_ttl(QuoteTTL::new(10_000, 10_000)).await?;
     }
@@ -750,7 +849,7 @@ async fn start_services_with_shutdown(
 
     let listener = tokio::net::TcpListener::bind(socket_addr).await?;
 
-    tracing::debug!("listening on {}", listener.local_addr().unwrap());
+    tracing::info!("listening on {}", listener.local_addr().unwrap());
 
     // Wait for axum server to complete with custom shutdown signal
     let axum_result = axum::serve(listener, mint_service).with_graceful_shutdown(shutdown_signal);
@@ -794,20 +893,32 @@ fn work_dir() -> Result<PathBuf> {
     Ok(dir)
 }
 
-/// The main entry point for the application when used as a library.
-///
-/// This asynchronous function performs the following steps:
-/// 1. Executes the initial setup, including loading configurations and initializing the database.
-/// 2. Configures a `MintBuilder` instance with the local store and keystore based on the database.
-/// 3. Applies additional custom configurations and authentication setup for the `MintBuilder`.
-/// 4. Constructs a `Mint` instance from the configured `MintBuilder`.
-/// 5. Checks and resolves the status of any pending mint and melt quotes.
+/// The main entry point for the application when used as a library
 pub async fn run_mintd(
     work_dir: &Path,
     settings: &config::Settings,
     db_password: Option<String>,
+    enable_logging: bool,
 ) -> Result<()> {
-    run_mintd_with_shutdown(work_dir, settings, shutdown_signal(), db_password).await
+    let _guard = if enable_logging {
+        setup_tracing(work_dir, &settings.info.logging)?
+    } else {
+        None
+    };
+
+    let result = run_mintd_with_shutdown(work_dir, settings, shutdown_signal(), db_password).await;
+
+    // Explicitly drop the guard to ensure proper cleanup
+    if let Some(guard) = _guard {
+        tracing::info!("Shutting down logging worker thread");
+        drop(guard);
+        // Give the worker thread a moment to flush any remaining logs
+        tokio::time::sleep(tokio::time::Duration::from_millis(100)).await;
+    }
+
+    tracing::info!("Mintd shutdown");
+
+    result
 }
 
 /// Run mintd with a custom shutdown signal
@@ -836,7 +947,7 @@ pub async fn run_mintd_with_shutdown(
     // Pending melt quotes where the payment has **failed** inputs are reset to unspent
     mint.check_pending_melt_quotes().await?;
 
-    start_services_with_shutdown(
+    let result = start_services_with_shutdown(
         mint.clone(),
         settings,
         ln_routers,
@@ -844,7 +955,11 @@ pub async fn run_mintd_with_shutdown(
         mint.mint_info().await?,
         shutdown_signal,
     )
-    .await?;
+    .await;
 
-    Ok(())
+    // Ensure any remaining tracing data is flushed
+    // This is particularly important for file-based logging
+    tracing::debug!("Flushing remaining trace data");
+
+    result
 }

+ 3 - 7
crates/cdk-mintd/src/main.rs

@@ -16,7 +16,7 @@ compile_error!(
 
 use anyhow::Result;
 use cdk_mintd::cli::CLIArgs;
-use cdk_mintd::{get_work_directory, load_settings, setup_tracing};
+use cdk_mintd::{get_work_directory, load_settings};
 use clap::Parser;
 use tokio::main;
 
@@ -24,12 +24,7 @@ use tokio::main;
 async fn main() -> Result<()> {
     let args = CLIArgs::parse();
 
-    if args.enable_logging {
-        setup_tracing();
-    }
-
     let work_dir = get_work_directory(&args).await?;
-
     let settings = load_settings(&work_dir, args.config)?;
 
     #[cfg(feature = "sqlcipher")]
@@ -38,5 +33,6 @@ async fn main() -> Result<()> {
     #[cfg(not(feature = "sqlcipher"))]
     let password = None;
 
-    cdk_mintd::run_mintd(&work_dir, &settings, password).await
+    // Use the main function that handles logging setup and cleanup
+    cdk_mintd::run_mintd(&work_dir, &settings, password, args.enable_logging).await
 }

+ 0 - 1
crates/cdk-sql-common/src/mint/mod.rs

@@ -700,7 +700,6 @@ VALUES (:quote_id, :amount, :timestamp);
 
     #[instrument(skip_all)]
     async fn add_mint_quote(&mut self, quote: MintQuote) -> Result<(), Self::Err> {
-        tracing::debug!("Adding quote with: {}", quote.payment_method);
         query(
             r#"
                 INSERT INTO mint_quote (

+ 2 - 2
crates/cdk/src/mint/auth/mod.rs

@@ -49,14 +49,14 @@ impl Mint {
         endpoint: &ProtectedEndpoint,
     ) -> Result<(), Error> {
         let auth_required = if let Some(auth_required) = self.is_protected(endpoint).await? {
-            tracing::info!(
+            tracing::trace!(
                 "Auth required for endpoint: {:?}, type: {:?}",
                 endpoint,
                 auth_required
             );
             auth_required
         } else {
-            tracing::debug!("No auth required for endpoint: {:?}", endpoint);
+            tracing::trace!("No auth required for endpoint: {:?}", endpoint);
             return Ok(());
         };
 

+ 3 - 3
crates/cdk/src/mint/issue/mod.rs

@@ -293,7 +293,7 @@ impl Mint {
             quote.id,
             amount,
             unit,
-            create_invoice_response.request_lookup_id,
+            create_invoice_response.request_lookup_id.to_string(),
         );
 
         let mut tx = self.localstore.begin_transaction().await?;
@@ -364,7 +364,7 @@ impl Mint {
         if wait_payment_response.payment_amount == Amount::ZERO {
             tracing::warn!(
                 "Received payment response with 0 amount with payment id {}.",
-                wait_payment_response.payment_id
+                wait_payment_response.payment_id.to_string()
             );
 
             return Err(Error::AmountUndefined);
@@ -413,7 +413,7 @@ impl Mint {
             "Received payment notification of {} for mint quote {} with payment id {}",
             wait_payment_response.payment_amount,
             mint_quote.id,
-            wait_payment_response.payment_id
+            wait_payment_response.payment_id.to_string()
         );
 
         let quote_state = mint_quote.state();

+ 31 - 8
crates/cdk/src/mint/melt.rs

@@ -202,7 +202,8 @@ impl Mint {
         );
 
         tracing::debug!(
-            "New melt quote {} for {} {} with request id {}",
+            "New {} melt quote {} for {} {} with request id {}",
+            quote.payment_method,
             quote.id,
             amount_quote_unit,
             unit,
@@ -308,7 +309,8 @@ impl Mint {
         );
 
         tracing::debug!(
-            "New melt quote {} for {} {} with request id {}",
+            "New {} melt quote {} for {} {} with request id {}",
+            quote.payment_method,
             quote.id,
             amount,
             unit,
@@ -578,7 +580,7 @@ impl Mint {
                 // correct and the mint should pay the full invoice amount if inputs
                 // > `then quote.amount` are included. This is checked in the
                 // `verify_melt` method.
-                let partial_amount = match quote.unit {
+                let _partial_amount = match quote.unit {
                     CurrencyUnit::Sat | CurrencyUnit::Msat => {
                         match self.check_melt_expected_ln_fees(&quote, melt_request).await {
                             Ok(amount) => amount,
@@ -590,10 +592,10 @@ impl Mint {
                     }
                     _ => None,
                 };
-                tracing::debug!("partial_amount: {:?}", partial_amount);
+
                 let ln = match self.payment_processors.get(&PaymentProcessorKey::new(
                     quote.unit.clone(),
-                    PaymentMethod::Bolt11,
+                    quote.payment_method.clone(),
                 )) {
                     Some(ln) => ln,
                     None => {
@@ -613,6 +615,7 @@ impl Mint {
                         if pay.status == MeltQuoteState::Unknown
                             || pay.status == MeltQuoteState::Failed =>
                     {
+                        tracing::warn!("Got {} status when paying melt quote {} for {} {}. Checking with backend...", pay.status, quote.id, quote.amount, quote.unit);
                         let check_response =
                             if let Ok(ok) = check_payment_state(Arc::clone(ln), &quote).await {
                                 ok
@@ -733,6 +736,7 @@ impl Mint {
 
         Ok(res)
     }
+
     /// Process melt request marking proofs as spent
     /// The melt request must be verifyed using [`Self::verify_melt_request`]
     /// before calling [`Self::process_melt_request`]
@@ -746,8 +750,6 @@ impl Mint {
         payment_preimage: Option<String>,
         total_spent: Amount,
     ) -> Result<MeltQuoteBolt11Response<Uuid>, Error> {
-        tracing::debug!("Processing melt quote: {}", melt_request.quote());
-
         let input_ys = melt_request.inputs().ys()?;
 
         proof_writer
@@ -763,8 +765,10 @@ impl Mint {
 
         let mut change = None;
 
+        let inputs_amount = melt_request.inputs_amount()?;
+
         // Check if there is change to return
-        if melt_request.inputs_amount()? > total_spent {
+        if inputs_amount > total_spent {
             // Check if wallet provided change outputs
             if let Some(outputs) = melt_request.outputs().clone() {
                 let blinded_messages: Vec<PublicKey> =
@@ -831,10 +835,17 @@ impl Mint {
                 proof_writer.commit();
                 tx.commit().await?;
             } else {
+                tracing::info!(
+                    "Inputs for {} {} greater then spent on melt {} but change outputs not provided.",
+                    quote.id,
+                    inputs_amount,
+                    total_spent
+                );
                 proof_writer.commit();
                 tx.commit().await?;
             }
         } else {
+            tracing::debug!("No change required for melt {}", quote.id);
             proof_writer.commit();
             tx.commit().await?;
         }
@@ -846,6 +857,18 @@ impl Mint {
             MeltQuoteState::Paid,
         );
 
+        tracing::debug!(
+            "Melt for quote {} completed total spent {}, total inputs: {}, change given: {}",
+            quote.id,
+            total_spent,
+            inputs_amount,
+            change
+                .as_ref()
+                .map(|c| Amount::try_sum(c.iter().map(|a| a.amount))
+                    .expect("Change cannot overflow"))
+                .unwrap_or_default()
+        );
+
         Ok(MeltQuoteBolt11Response {
             amount: quote.amount,
             paid: Some(true),

+ 7 - 7
crates/cdk/src/mint/mod.rs

@@ -441,7 +441,7 @@ impl Mint {
             loop {
                 tokio::select! {
                     _ = shutdown.notified() => {
-                        println!("Shutting down payment processors");
+                        tracing::info!("Shutting down payment processors");
                         break;
                     }
                     Some(result) = join_set.join_next() => {
@@ -475,7 +475,6 @@ impl Mint {
                     match result {
                         Ok(mut stream) => {
                             while let Some(request_lookup_id) = stream.next().await {
-                                tracing::debug!("Received payment {:?}", request_lookup_id);
                                 if let Err(e) = Self::handle_payment_notification(
                                     &localstore,
                                     &pubsub_manager,
@@ -517,11 +516,6 @@ impl Mint {
             .get_mint_quote_by_request_lookup_id(&wait_payment_response.payment_identifier)
             .await
         {
-            tracing::debug!(
-                "Received payment {} for quote-id {}",
-                wait_payment_response.payment_identifier,
-                mint_quote.id
-            );
             Self::handle_mint_quote_payment(
                 &mut tx,
                 &mint_quote,
@@ -747,6 +741,12 @@ impl Mint {
         tx.increment_mint_quote_amount_paid(&mint_quote.id, amount, melt_quote.id.to_string())
             .await?;
 
+        tracing::info!(
+            "Melt quote {} paid Mint quote {}",
+            melt_quote.id,
+            mint_quote.id
+        );
+
         Ok(Some(amount))
     }
 

+ 8 - 0
misc/interactive_regtest_mprocs.sh

@@ -184,6 +184,9 @@ export CDK_MINTD_LISTEN_HOST="127.0.0.1"
 export CDK_MINTD_LISTEN_PORT=8085
 export CDK_MINTD_LN_BACKEND="cln"
 export CDK_MINTD_MNEMONIC="eye survey guilt napkin crystal cup whisper salt luggage manage unveil loyal"
+export CDK_MINTD_LOGGING_OUTPUT="both"
+export CDK_MINTD_LOGGING_CONSOLE_LEVEL="debug"
+export CDK_MINTD_LOGGING_FILE_LEVEL="debug"
 export RUST_BACKTRACE=1
 export CDK_MINTD_DATABASE="$CDK_MINTD_DATABASE"
 
@@ -192,6 +195,7 @@ echo "Project root: $PROJECT_ROOT"
 echo "Working directory: \$CDK_MINTD_WORK_DIR"
 echo "CLN RPC path: \$CDK_MINTD_CLN_RPC_PATH"
 echo "Database type: \$CDK_MINTD_DATABASE"
+echo "Logging: \$CDK_MINTD_LOGGING_OUTPUT (console: \$CDK_MINTD_LOGGING_CONSOLE_LEVEL, file: \$CDK_MINTD_LOGGING_FILE_LEVEL)"
 echo "---"
 
 exec cargo run --bin cdk-mintd
@@ -209,6 +213,9 @@ export CDK_MINTD_LISTEN_HOST="127.0.0.1"
 export CDK_MINTD_LISTEN_PORT=8087
 export CDK_MINTD_LN_BACKEND="lnd"
 export CDK_MINTD_MNEMONIC="cattle gold bind busy sound reduce tone addict baby spend february strategy"
+export CDK_MINTD_LOGGING_OUTPUT="both"
+export CDK_MINTD_LOGGING_CONSOLE_LEVEL="debug"
+export CDK_MINTD_LOGGING_FILE_LEVEL="debug"
 export RUST_BACKTRACE=1
 export CDK_MINTD_DATABASE="$CDK_MINTD_DATABASE"
 
@@ -217,6 +224,7 @@ echo "Project root: $PROJECT_ROOT"
 echo "Working directory: \$CDK_MINTD_WORK_DIR"
 echo "LND address: \$CDK_MINTD_LND_ADDRESS"
 echo "Database type: \$CDK_MINTD_DATABASE"
+echo "Logging: \$CDK_MINTD_LOGGING_OUTPUT (console: \$CDK_MINTD_LOGGING_CONSOLE_LEVEL, file: \$CDK_MINTD_LOGGING_FILE_LEVEL)"
 echo "---"
 
 exec cargo run --bin cdk-mintd