diff --git a/crates/cdk-agicash/src/lib.rs b/crates/cdk-agicash/src/lib.rs index 14620ff8c..ac531453e 100644 --- a/crates/cdk-agicash/src/lib.rs +++ b/crates/cdk-agicash/src/lib.rs @@ -34,6 +34,11 @@ use square_api::SquareApiClient; /// Hardcoded lookup window (seconds on each side of invoice timestamp) pub const SQUARE_PAYMENT_LOOKUP_WINDOW_SECS: u64 = 2; +/// Format epoch seconds as a human-readable UTC string for log messages. +fn epoch_to_human(epoch: u64) -> String { + square_api::epoch_to_rfc3339(epoch) +} + /// Validation strategy for closed-loop payments #[allow(missing_debug_implementations)] pub enum ClosedLoopValidator { @@ -43,6 +48,8 @@ pub enum ClosedLoopValidator { api_client: SquareApiClient, /// Merchant name shown in rejection error messages valid_destination_name: String, + /// Active Square location IDs to search for payments across all locations + location_ids: Vec, }, /// Internal validation — only invoices created by this mint are allowed. /// @@ -88,12 +95,14 @@ impl ClosedLoopPayment { inner: Arc + Send + Sync>, api_client: SquareApiClient, valid_destination_name: String, + location_ids: Vec, ) -> Self { Self { inner, validator: ClosedLoopValidator::Square { api_client, valid_destination_name, + location_ids, }, } } @@ -118,7 +127,11 @@ impl ClosedLoopPayment { ClosedLoopValidator::Square { api_client, valid_destination_name, - } => Self::validate_square(bolt11, api_client, valid_destination_name).await, + location_ids, + } => { + Self::validate_square(bolt11, api_client, valid_destination_name, location_ids) + .await + } ClosedLoopValidator::Internal { known_hashes, destination_name, @@ -131,6 +144,7 @@ impl ClosedLoopPayment { bolt11: &Bolt11Invoice, api_client: &SquareApiClient, valid_destination_name: &str, + location_ids: &[String], ) -> Result<(), payment::Error> { // Pre-filter: check description contains valid_destination_name let (description_matches, is_hashed) = match bolt11.description() { @@ -166,14 +180,28 @@ impl ClosedLoopPayment { // Check invoice timestamp against Square payment timestamps let invoice_epoch = bolt11.duration_since_epoch().as_secs(); + let invoice_time = epoch_to_human(invoice_epoch); + + tracing::debug!( + invoice_epoch, + invoice_time = %invoice_time, + window_secs = SQUARE_PAYMENT_LOOKUP_WINDOW_SECS, + destination = %valid_destination_name, + "Checking invoice against Square payments" + ); if api_client - .has_lightning_payment_near_timestamp(invoice_epoch, SQUARE_PAYMENT_LOOKUP_WINDOW_SECS) + .has_lightning_payment_near_timestamp( + invoice_epoch, + SQUARE_PAYMENT_LOOKUP_WINDOW_SECS, + location_ids, + ) .await? { tracing::debug!( - "Square payment found near invoice timestamp {invoice_epoch} (window={}s)", - SQUARE_PAYMENT_LOOKUP_WINDOW_SECS + invoice_epoch, + invoice_time = %invoice_time, + "Square payment matched — allowing melt" ); return Ok(()); } @@ -181,10 +209,23 @@ impl ClosedLoopPayment { #[cfg(feature = "prometheus")] metrics::AGICASH_METRICS.record_payment_not_allowed("no_square_payment_found"); - tracing::info!( - "No Square payment found near invoice timestamp {invoice_epoch} (window={}s)", - SQUARE_PAYMENT_LOOKUP_WINDOW_SECS + tracing::warn!( + invoice_epoch, + invoice_time = %invoice_time, + window_secs = SQUARE_PAYMENT_LOOKUP_WINDOW_SECS, + destination = %valid_destination_name, + "REJECTED: No Square Lightning payment found in time window. \ + Invoice was created at {} but no matching Square payment exists \ + within +/-{}s of that timestamp.", + invoice_time, + SQUARE_PAYMENT_LOOKUP_WINDOW_SECS, ); + + // Log all Lightning payments in the last 3 hours for debugging + api_client + .log_recent_lightning_payments(3, invoice_epoch, location_ids) + .await; + Err(payment::Error::PaymentNotAllowed(format!( "This ecash can only be spent at {}", valid_destination_name diff --git a/crates/cdk-agicash/src/square_api.rs b/crates/cdk-agicash/src/square_api.rs index 81f497d9f..6fb117f7c 100644 --- a/crates/cdk-agicash/src/square_api.rs +++ b/crates/cdk-agicash/src/square_api.rs @@ -12,7 +12,9 @@ use tracing::warn; use crate::config::SquareEnvironment; use crate::credentials::CredentialProvider; use crate::error::Error; -use crate::types::{DigitalWalletBrand, ListPaymentsResponse, PaymentSourceType}; +use crate::types::{ + DigitalWalletBrand, ListLocationsResponse, ListPaymentsResponse, PaymentSourceType, +}; #[cfg(feature = "prometheus")] use crate::metrics::AGICASH_METRICS; @@ -52,6 +54,35 @@ impl SquareApiClient { } } + /// List all active Square locations for this merchant. + /// + /// Calls `GET /v2/locations` and filters to `status == "ACTIVE"`. + /// See + pub async fn list_locations(&self) -> Result, Error> { + let url = format!("{}/v2/locations", self.base_url); + let response: ListLocationsResponse = self.get_with_retry(&url, &[]).await?; + + let locations = response.locations.unwrap_or_default(); + let active: Vec = locations + .into_iter() + .filter(|loc| { + loc.status + .as_deref() + .is_some_and(|s| s.eq_ignore_ascii_case("ACTIVE")) + }) + .map(|loc| { + tracing::debug!( + location_id = %loc.id, + name = ?loc.name, + "Active Square location" + ); + loc.id + }) + .collect(); + + Ok(active) + } + /// List payments from Square API with time range and pagination. /// /// Calls `GET /v2/payments` with time-range filtering on `created_at`. @@ -61,12 +92,14 @@ impl SquareApiClient { /// - `begin_time` / `end_time`: RFC 3339 timestamps filtering on `created_at` /// - `cursor`: pagination cursor from a previous response /// - `limit`: max results per page (capped at 100 by Square) + /// - `location_id`: optional location to scope the query to pub async fn list_payments( &self, begin_time: &str, end_time: &str, cursor: Option<&str>, limit: u32, + location_id: Option<&str>, ) -> Result { let url = format!("{}/v2/payments", self.base_url); @@ -81,43 +114,221 @@ impl SquareApiClient { params.push(("cursor", c.to_string())); } + if let Some(loc) = location_id { + params.push(("location_id", loc.to_string())); + } + self.get_with_retry(&url, ¶ms).await } /// Query Square for payments near an invoice timestamp and check whether any /// are Lightning wallet payments. + /// + /// When `location_ids` is non-empty, each location is queried individually so + /// that payments at any location are found (the Square API defaults to the + /// merchant's main location when no `location_id` is provided). pub async fn has_lightning_payment_near_timestamp( &self, invoice_epoch_secs: u64, lookup_window_secs: u64, + location_ids: &[String], ) -> Result { let begin_epoch = invoice_epoch_secs.saturating_sub(lookup_window_secs); let end_epoch = invoice_epoch_secs.saturating_add(lookup_window_secs); let begin_time = epoch_to_rfc3339(begin_epoch); let end_time = epoch_to_rfc3339(end_epoch); - let mut cursor: Option = None; + tracing::debug!( + invoice_epoch = invoice_epoch_secs, + window_secs = lookup_window_secs, + begin_time = %begin_time, + end_time = %end_time, + num_locations = location_ids.len(), + "Querying Square for payments near invoice timestamp" + ); + + // If no locations were discovered, fall back to a single call without + // location_id (backwards-compatible with merchants that have one location). + let location_iter: Vec> = if location_ids.is_empty() { + vec![None] + } else { + location_ids.iter().map(|id| Some(id.as_str())).collect() + }; + + for loc_id in &location_iter { + tracing::debug!( + location_id = ?loc_id, + "Checking location for Lightning payments" + ); + + let mut cursor: Option = None; + let mut total_payments = 0u32; + let mut pages = 0u32; + + loop { + let response = self + .list_payments( + &begin_time, + &end_time, + cursor.as_deref(), + PAGE_LIMIT, + *loc_id, + ) + .await?; + + pages += 1; + + if let Some(ref payments) = response.payments { + total_payments += payments.len() as u32; + + for p in payments { + let is_match = is_lightning_payment(p); + tracing::debug!( + payment_id = %p.id, + created_at = %p.created_at, + source_type = ?p.source_type, + wallet_brand = ?p.wallet_details.as_ref().and_then(|wd| wd.brand), + is_lightning = is_match, + location_id = ?loc_id, + "Square payment in window" + ); + if is_match { + tracing::debug!( + total_payments, + pages, + location_id = ?loc_id, + "Found matching Lightning payment" + ); + return Ok(true); + } + } + } else { + tracing::debug!( + page = pages, + location_id = ?loc_id, + "Square returned no payments on this page" + ); + } + + cursor = response.cursor; + if cursor.is_none() { + break; + } + } - loop { - let response = self - .list_payments(&begin_time, &end_time, cursor.as_deref(), PAGE_LIMIT) - .await?; + tracing::debug!( + total_payments, + pages, + location_id = ?loc_id, + "No Lightning payment at this location" + ); + } - if response - .payments - .as_ref() - .is_some_and(|payments| payments.iter().any(is_lightning_payment)) - { - return Ok(true); - } + tracing::debug!( + num_locations = location_iter.len(), + "No Lightning payment found at any location" + ); + Ok(false) + } - cursor = response.cursor; - if cursor.is_none() { - break; + /// Fetch and log all Lightning payments from the last `hours` hours. + /// Called on the rejection path to help debug timestamp mismatches. + /// Iterates over all `location_ids` (or makes a single unscoped call if empty). + pub async fn log_recent_lightning_payments( + &self, + hours: u64, + invoice_epoch_secs: u64, + location_ids: &[String], + ) { + let now_epoch = std::time::SystemTime::now() + .duration_since(std::time::UNIX_EPOCH) + .unwrap_or_default() + .as_secs(); + let begin_epoch = now_epoch.saturating_sub(hours * 3600); + let begin_time = epoch_to_rfc3339(begin_epoch); + let end_time = epoch_to_rfc3339(now_epoch); + + tracing::warn!( + begin_time = %begin_time, + end_time = %end_time, + hours, + num_locations = location_ids.len(), + "Fetching all Square payments in last {hours}h for debugging" + ); + + let location_iter: Vec> = if location_ids.is_empty() { + vec![None] + } else { + location_ids.iter().map(|id| Some(id.as_str())).collect() + }; + + let mut lightning_count = 0u32; + let mut total_count = 0u32; + + for loc_id in &location_iter { + let mut cursor: Option = None; + + loop { + let response = match self + .list_payments(&begin_time, &end_time, cursor.as_deref(), PAGE_LIMIT, *loc_id) + .await + { + Ok(r) => r, + Err(e) => { + tracing::error!( + location_id = ?loc_id, + "Failed to fetch recent payments for debug log: {e}" + ); + break; + } + }; + + if let Some(ref payments) = response.payments { + total_count += payments.len() as u32; + for p in payments { + if is_lightning_payment(p) { + lightning_count += 1; + let bolt11_preview = p + .wallet_details + .as_ref() + .and_then(|wd| wd.lightning_details.as_ref()) + .and_then(|ld| ld.payment_url.as_deref()) + .map(|url| { + if url.len() > 40 { + format!("{}...", &url[..40]) + } else { + url.to_string() + } + }) + .unwrap_or_else(|| "none".into()); + + tracing::warn!( + payment_id = %p.id, + created_at = %p.created_at, + invoice_epoch = invoice_epoch_secs, + invoice_time = %epoch_to_rfc3339(invoice_epoch_secs), + bolt11 = %bolt11_preview, + location_id = ?loc_id, + "DEBUG: Recent Lightning payment from Square" + ); + } + } + } + + cursor = response.cursor; + if cursor.is_none() { + break; + } } } - Ok(false) + tracing::warn!( + lightning_count, + total_count, + hours, + num_locations = location_iter.len(), + "DEBUG: Total Square payments in last {hours}h: {total_count} total, {lightning_count} Lightning" + ); } // --- Generic HTTP helpers with 401-retry --- @@ -224,7 +435,7 @@ fn is_lightning_payment(payment: &crate::types::SquarePayment) -> bool { } /// Convert epoch seconds to RFC 3339 UTC string. -fn epoch_to_rfc3339(epoch: u64) -> String { +pub(crate) fn epoch_to_rfc3339(epoch: u64) -> String { let days = epoch / 86400; let time_of_day = epoch % 86400; let hours = time_of_day / 3600; diff --git a/crates/cdk-agicash/src/types.rs b/crates/cdk-agicash/src/types.rs index 57cba2bb3..641119d35 100644 --- a/crates/cdk-agicash/src/types.rs +++ b/crates/cdk-agicash/src/types.rs @@ -5,6 +5,28 @@ use serde::Deserialize; +/// Square List Locations API response. +/// +/// See +#[derive(Debug, Clone, Deserialize)] +pub struct ListLocationsResponse { + /// List of locations (may be absent if no results) + pub locations: Option>, +} + +/// A Square location object (subset of fields we use). +/// +/// See +#[derive(Debug, Clone, Deserialize)] +pub struct SquareLocation { + /// Square location ID + pub id: String, + /// Human-readable location name + pub name: Option, + /// Location status (`ACTIVE` or `INACTIVE`) + pub status: Option, +} + /// Square List Payments API response. /// /// See diff --git a/crates/cdk-mintd/src/lib.rs b/crates/cdk-mintd/src/lib.rs index 708959e6d..5396964f5 100644 --- a/crates/cdk-mintd/src/lib.rs +++ b/crates/cdk-mintd/src/lib.rs @@ -654,11 +654,12 @@ async fn configure_lightning_backend( #[cfg(feature = "agicash")] let backend: Arc< dyn MintPayment + Send + Sync, - > = if let Some((ref api_client, ref name)) = agicash_square { + > = if let Some((ref api_client, ref name, ref location_ids)) = agicash_square { Arc::new(cdk_agicash::ClosedLoopPayment::new_square( Arc::new(strike), api_client.clone(), name.clone(), + location_ids.clone(), )) } else { Arc::new(strike) @@ -697,7 +698,7 @@ async fn configure_lightning_backend( #[cfg(feature = "agicash")] async fn setup_agicash_square( settings: &config::Settings, -) -> Result> { +) -> Result)>> { let agicash_config = match settings.agicash.as_ref() { Some(c) => c, None => return Ok(None), @@ -740,6 +741,25 @@ async fn setup_agicash_square( let api_client = cdk_agicash::square_api::SquareApiClient::new(&square_env, Arc::new(provider)); + + // Fetch all active locations so payment lookups cover every register + let location_ids = match api_client.list_locations().await { + Ok(ids) => { + tracing::info!( + "Discovered {} active Square location(s): {:?}", + ids.len(), + ids + ); + ids + } + Err(e) => { + tracing::warn!( + "Failed to fetch Square locations, will use default location only: {e}" + ); + Vec::new() + } + }; + tracing::info!( "Agicash Square closed-loop validation enabled (on-demand lookup window={}s)", cdk_agicash::SQUARE_PAYMENT_LOOKUP_WINDOW_SECS @@ -747,6 +767,7 @@ async fn setup_agicash_square( Ok(Some(( api_client, closed_loop.valid_destination_name.clone(), + location_ids, ))) } }