Extensively refactor crypto watcher logging and add comprehensive payment string representations

Infrastructure improvements:
- Add CryptoWatcherLogger class with centralized logging methods
- Add comprehensive __str__ and __repr__ methods to CryptoPayment model
- Include user display name and shop name in payment logs

Logging refactoring:
- Convert 101+ logger calls to use centralized patterns
- Replace repetitive f-string patterns with payment object logging
- Add standardized methods for state transitions, refunds, sweeps
- Eliminate duplicate payment context formatting

DRY improvements:
- Single point of control for payment log formatting
- Consistent error handling with payment context
- Standardized transaction and operation logging
- Enhanced debugging with rich payment information

Testing:
- Add 16 comprehensive unit tests for string representation methods
- Test coverage for all payment states and edge cases
- Maintain 100% functionality with improved maintainability
This commit is contained in:
Russell Ballestrini 2025-09-30 20:11:01 -04:00
parent 01c1d237e1
commit 71f8f2b467
8 changed files with 770 additions and 186 deletions

View file

@ -7,9 +7,12 @@ Handles:
- Expired quotes: Refund late payments minus 9% restocking fee
"""
import logging
from decimal import Decimal
from ..models.user_crypto_refund_address import get_user_crypto_refund_address
logger = logging.getLogger(__name__)
RESTOCKING_FEE_PERCENT = Decimal("0.09") # 9% restocking fee
OVERPAYMENT_THRESHOLD_PERCENT = Decimal("0.05") # 5% overpayment allowed before refund
@ -183,12 +186,20 @@ class PaymentRescue:
else "koinu" if coin_type == "DOGE" else "atomic units"
)
logger.info(f"Attempting to refund payment {refund_details['payment_id']}")
logger.info(
f"Refund amount: {refund_amount_coin} {coin_type} ({refund_amount_atomic} {atomic_unit_name})"
)
logger.info(f"Refund address: {refund_details['refund_address']}")
logger.info(f"Refund reason: {refund_details['reason']}")
if payment:
logger.info(f"Attempting to refund: {payment}")
logger.info(
f"Refund amount: {refund_amount_coin} {coin_type} ({refund_amount_atomic} {atomic_unit_name})"
)
logger.info(f"Refund address: {refund_details['refund_address']}")
logger.info(f"Refund reason: {refund_details['reason']}")
else:
logger.info(f"Attempting to refund payment {refund_details['payment_id']}")
logger.info(
f"Refund amount: {refund_amount_coin} {coin_type} ({refund_amount_atomic} {atomic_unit_name})"
)
logger.info(f"Refund address: {refund_details['refund_address']}")
logger.info(f"Refund reason: {refund_details['reason']}")
# Check if incoming payment has enough confirmations before allowing refund
from .crypto_watcher import get_coin_config
@ -197,9 +208,7 @@ class PaymentRescue:
required_confirmations = coin_config.get("confirmations_required", 10)
if payment and payment.current_confirmations < required_confirmations:
logger.info(
f"Refund delayed - incoming payment has {payment.current_confirmations}/{required_confirmations} confirmations"
)
logger.info(f"Refund delayed - insufficient confirmations: {payment}")
return {
"success": False,
"error": f"Incoming payment needs {required_confirmations - payment.current_confirmations} more confirmations before refund",
@ -283,7 +292,12 @@ class PaymentRescue:
else:
raise ValueError(f"Refund not supported for coin type: {coin_type}")
logger.info(f"Refund transaction successful: {tx_result}")
if payment:
logger.info(f"Refund transaction successful: {payment} - {tx_result}")
else:
logger.info(
f"Refund transaction successful for payment {refund_details['payment_id']}: {tx_result}"
)
return {
"success": True,
@ -293,7 +307,10 @@ class PaymentRescue:
}
except Exception as e:
logger.error(
f"Refund failed for payment {refund_details['payment_id']}: {e}"
)
if payment:
logger.error(f"Refund failed: {payment} - {e}")
else:
logger.error(
f"Refund failed for payment {refund_details['payment_id']}: {e}"
)
return {"success": False, "error": str(e), "refund_details": refund_details}

View file

@ -26,6 +26,89 @@ from ..models.user_crypto_refund_address import UserCryptoRefundAddress
logger = logging.getLogger(__name__)
class CryptoWatcherLogger:
"""Centralized logging helper for crypto watcher operations."""
def __init__(self, logger_instance=None):
self.logger = logger_instance or logger
def payment_info(self, payment, message: str, **kwargs):
"""Log payment-related info with standardized format."""
context = f" {kwargs.get('context', '')}" if kwargs.get("context") else ""
self.logger.info(f"{message}: {payment}{context}")
def payment_warning(self, payment, message: str, **kwargs):
"""Log payment-related warning with standardized format."""
context = f" {kwargs.get('context', '')}" if kwargs.get("context") else ""
self.logger.warning(f"{message}: {payment}{context}")
def payment_error(self, payment, message: str, error=None, **kwargs):
"""Log payment-related error with standardized format."""
context = f" {kwargs.get('context', '')}" if kwargs.get("context") else ""
error_detail = f" - {error}" if error else ""
self.logger.error(f"{message}: {payment}{context}{error_detail}")
def payment_debug(self, payment, message: str, **kwargs):
"""Log payment-related debug with standardized format."""
context = f" {kwargs.get('context', '')}" if kwargs.get("context") else ""
self.logger.debug(f"{message}: {payment}{context}")
def transaction_processing(
self, payment, action: str, tx_hash: str = None, amount: int = None
):
"""Log transaction processing events."""
tx_info = f" tx:{tx_hash[:16]}..." if tx_hash else ""
amount_info = f" amount:{amount}" if amount is not None else ""
self.logger.info(f"{action}: {payment}{tx_info}{amount_info}")
def state_transition(
self, payment, old_status: str, new_status: str, reason: str = ""
):
"""Log state transitions with context."""
reason_info = f" ({reason})" if reason else ""
self.logger.info(
f"State transition: {payment} {old_status}{new_status}{reason_info}"
)
def refund_operation(
self, payment, operation: str, tx_hash: str = None, amount: int = None
):
"""Log refund operations."""
tx_info = f" tx:{tx_hash[:16]}..." if tx_hash else ""
amount_info = f" amount:{amount}" if amount is not None else ""
self.logger.info(f"Refund {operation}: {payment}{tx_info}{amount_info}")
def sweep_operation(
self, payment, operation: str, tx_hash: str = None, amount: int = None
):
"""Log sweep operations."""
tx_info = f" tx:{tx_hash[:16]}..." if tx_hash else ""
amount_info = f" amount:{amount}" if amount is not None else ""
self.logger.info(f"Sweep {operation}: {payment}{tx_info}{amount_info}")
def confirmation_update(self, payment, old_count: int, new_count: int):
"""Log confirmation count updates."""
self.logger.info(f"Confirmations updated: {payment} {old_count}{new_count}")
def processing_cycle(
self, message: str, payment_count: int = None, cycle_info: str = ""
):
"""Log processing cycle information."""
count_info = f" ({payment_count} payments)" if payment_count is not None else ""
cycle_detail = f" {cycle_info}" if cycle_info else ""
self.logger.info(f"Processing cycle: {message}{count_info}{cycle_detail}")
def error_with_context(self, message: str, error, payment=None, context: str = ""):
"""Log errors with payment context when available."""
payment_info = f" {payment}" if payment else ""
context_info = f" ({context})" if context else ""
self.logger.error(f"{message}{payment_info}{context_info} - {error}")
# Create logger instance for module use
log = CryptoWatcherLogger()
def _get_user_refund_address(dbsession, user_id, coin_type):
"""Get user's saved refund address for the given coin type."""
if not user_id:
@ -152,8 +235,9 @@ def _create_duplicate_payment(original_payment, tx, coin_type, dbsession=None):
dbsession, original_payment.user_id, coin_type
)
if refund_address:
logger.info(
f"Using saved refund address for user {original_payment.user_id}: {refund_address[:16]}..."
log.payment_info(
original_payment,
f"Using saved refund address: {refund_address[:16]}...",
)
# Create new payment object for this duplicate using proper constructor
@ -222,17 +306,15 @@ def _should_process_late_payment(payment, tx):
# DOGE/BTC amount is already in atomic units
tx_amount = int(float(tx.get("amount", 0)) * 1e8)
logger.info(
f"_should_process_late_payment check: payment {payment.id}, status={payment.status}, "
f"received_amount={payment.received_amount}, tx_amount={tx_amount}"
)
log.payment_debug(payment, f"Late payment check - tx_amount={tx_amount}")
# Edge Case: Any payment with non-pending status means invalid multiple payment
# ALL multiple payments are invalid - no legitimate double payments exist
if payment.status != CryptoPayment.STATUS_PENDING and tx_amount > 0:
current_total = payment.received_amount + tx_amount
logger.info(
f"INVALID multiple payment detected for {payment.status} payment {payment.id}: received {payment.received_amount}, new {tx_amount}, total {current_total}"
log.payment_warning(
payment,
f"Invalid multiple payment detected - new {tx_amount}, total {current_total}",
)
# Log specific scenarios for clarity
@ -240,25 +322,31 @@ def _should_process_late_payment(payment, tx):
CryptoPayment.STATUS_EXPIRED,
CryptoPayment.STATUS_CANCELLED,
]:
logger.info(f"Late payment to {payment.status} quote {payment.id}")
log.payment_info(
payment, "Late payment detected", context="expired/cancelled quote"
)
elif payment.status in [
CryptoPayment.STATUS_CONFIRMED,
CryptoPayment.STATUS_CONFIRMED_OVERPAY,
CryptoPayment.STATUS_CONFIRMED_OVERPAY_REFUNDED,
CryptoPayment.STATUS_CONFIRMED_OVERPAY_REFUNDED_COMPLETE,
]:
logger.info(f"Double payment to completed order {payment.id}")
log.payment_info(
payment, "Double payment detected", context="completed order"
)
elif current_total > payment.expected_amount:
logger.info(
f"Overpayment detected for payment {payment.id}: expected {payment.expected_amount}, will receive {current_total}"
log.payment_info(
payment,
f"Overpayment detected",
context=f"expected {payment.expected_amount}, receiving {current_total}",
)
else:
logger.info(
f"Invalid multiple payment to {payment.status} payment {payment.id}"
log.payment_warning(
payment, "Invalid multiple payment detected", context="unknown scenario"
)
logger.info(
f"_should_process_late_payment: ACCEPTING non-pending payment {payment.id}"
log.payment_info(
payment, "Accepting non-pending payment", context="late payment processing"
)
return True
@ -267,14 +355,13 @@ def _should_process_late_payment(payment, tx):
CryptoPayment.STATUS_PENDING,
CryptoPayment.STATUS_CONFIRMED,
]:
logger.info(
f"_should_process_late_payment: ACCEPTING first payment to fresh quote {payment.id}"
)
log.payment_info(payment, "Accepting first payment to fresh quote")
return True
logger.info(
f"_should_process_late_payment: REJECTING payment {payment.id} - "
f"received_amount={payment.received_amount}, status={payment.status}, tx_amount={tx_amount}"
log.payment_info(
payment,
f"Rejecting late payment - tx_amount={tx_amount}",
context="validation failed",
)
return False
@ -312,17 +399,17 @@ def delete_invoice_for_terminal_state(dbsession, crypto_payment):
# Delete invoice for all other terminal states
invoice = crypto_payment.invoice
logger.info(
f"Deleting invoice {invoice.id} for terminal payment {crypto_payment.id} "
f"with status {crypto_payment.status}"
log.payment_info(
crypto_payment, f"Deleting invoice {invoice.id}", context="terminal payment"
)
# Delete the invoice first, then clear the reference
try:
delete_result = delete_invoice_by_id(dbsession, invoice.id)
if delete_result.get("success", False):
logger.info(
f"Successfully deleted invoice {invoice.id}: {delete_result.get('message', '')}"
log.payment_info(
crypto_payment,
f"Successfully deleted invoice {invoice.id}: {delete_result.get('message', '')}",
)
# Only clear the reference after successful deletion
crypto_payment.invoice_id = None
@ -333,7 +420,7 @@ def delete_invoice_for_terminal_state(dbsession, crypto_payment):
f"Failed to delete invoice {invoice.id}: {delete_result.get('message', 'Unknown error')}"
)
except Exception as e:
logger.error(f"Error deleting invoice {invoice.id}: {e}")
log.error_with_context(f"Error deleting invoice {invoice.id}", e)
def get_crypto_client(settings, coin_type):
@ -383,9 +470,9 @@ def sweep_restocking_fee(settings, payment, refund_details, dbsession, context="
current_confirmations = getattr(payment, "refund_confirmations", 0) or 0
if current_confirmations < required_confirmations:
logger.info(
f"Restocking fee sweep for {payment.id} requires {required_confirmations} confirmations, "
f"but refund only has {current_confirmations} - waiting"
log.payment_info(
payment,
f"Restocking fee sweep requires {required_confirmations} confirmations, refund has {current_confirmations} - waiting",
)
return
@ -438,15 +525,14 @@ def sweep_restocking_fee(settings, payment, refund_details, dbsession, context="
)
fee_tx_hash = transfer_result.get("tx_hash")
actual_swept = amount_to_send
logger.info(
f"XMR restocking fee: Sent {amount_to_send} (balance: {current_balance}, expected: {fee_amount}) from payment {payment.id}"
log.sweep_operation(
payment,
f"XMR restocking fee sent {amount_to_send} (balance: {current_balance}, expected: {fee_amount})",
)
else:
fee_tx_hash = None
actual_swept = 0
logger.warning(
f"XMR restocking fee: No balance available for payment {payment.id}"
)
log.payment_warning(payment, "XMR restocking fee: No balance available")
elif payment.coin_type == "DOGE":
# Smart sweep: Use exact 9% amount with balance check for safety
@ -465,31 +551,31 @@ def sweep_restocking_fee(settings, payment, refund_details, dbsession, context="
payment.shop_sweep_to_address, amount_to_send_crypto
)
actual_swept = amount_to_send_atomic
logger.info(
f"DOGE restocking fee: Sent {amount_to_send_atomic} (balance: {current_balance_atomic}, expected: {fee_amount}) from payment {payment.id}"
log.sweep_operation(
payment,
f"DOGE restocking fee sent {amount_to_send_atomic} (balance: {current_balance_atomic}, expected: {fee_amount})",
)
else:
fee_tx_hash = None
actual_swept = 0
logger.warning(
f"DOGE restocking fee: No balance available for payment {payment.id}"
log.payment_warning(
payment, "DOGE restocking fee: No balance available"
)
else:
logger.warning(
f"Unsupported coin type for restocking fee sweep: {payment.coin_type}"
log.payment_warning(
payment,
f"Unsupported coin type for restocking fee sweep: {payment.coin_type}",
)
return
if fee_tx_hash:
logger.info(
f"{context} restocking fee swept for payment {payment.id}: "
f"{Decimal(actual_swept) / atomic_units} {payment.coin_type} "
f"TX: {fee_tx_hash}"
log.sweep_operation(
payment, f"{context} restocking fee swept", fee_tx_hash, actual_swept
)
except Exception as e:
logger.error(
f"Failed to sweep {context.lower()} restocking fee for payment {payment.id}: {e}"
log.payment_error(
payment, f"Failed to sweep {context.lower()} restocking fee", e
)
@ -519,20 +605,20 @@ def process_confirmed_payment(env_request, crypto_payment, client, payment_rescu
"final_status": None,
}
logger.info(
f"Processing confirmed payment {crypto_payment.id} with proper order of operations"
log.payment_info(
crypto_payment, "Processing confirmed payment with proper order of operations"
)
try:
# STEP 1: Always finalize invoice first (customer gets their product)
# Check if invoice already finalized to make this idempotent
if not crypto_payment.is_finalized():
logger.info(f"Step 1: Finalizing invoice for payment {crypto_payment.id}")
log.payment_info(crypto_payment, "Step 1: Finalizing invoice")
finalize_invoice(env_request, crypto_payment, send_emails=True)
results["invoice_finalized"] = True
else:
logger.info(
f"Step 1: Invoice for payment {crypto_payment.id} already finalized - skipping"
log.payment_info(
crypto_payment, "Step 1: Invoice already finalized - skipping"
)
results["invoice_finalized"] = True # Already done
@ -552,9 +638,7 @@ def process_confirmed_payment(env_request, crypto_payment, client, payment_rescu
)
if refund_details:
logger.info(
f"Step 2: Processing overpayment refund for {crypto_payment.id}"
)
log.refund_operation(crypto_payment, "processing overpayment")
crypto_payment.status = CryptoPayment.STATUS_CONFIRMED_OVERPAY
crypto_payment.refund_reason = refund_details["reason"]
@ -567,15 +651,17 @@ def process_confirmed_payment(env_request, crypto_payment, client, payment_rescu
results["overpayment_refund"] = result
else:
# Refund already processed successfully in previous attempt
logger.info(
f"Overpayment refund for {crypto_payment.id} already processed - TX: {crypto_payment.refund_tx_hash}"
log.refund_operation(
crypto_payment,
"already processed",
crypto_payment.refund_tx_hash,
)
result = {"success": True, "tx_hash": crypto_payment.refund_tx_hash}
results["overpayment_refund"] = result
if result["success"]:
logger.info(
f"Overpayment refund successful for {crypto_payment.id}: TX {result['tx_hash']}"
log.refund_operation(
crypto_payment, "successful", result["tx_hash"]
)
# Set refund details but keep in overpaid status for now
crypto_payment.refund_tx_hash = result["tx_hash"]
@ -587,24 +673,24 @@ def process_confirmed_payment(env_request, crypto_payment, client, payment_rescu
)
# Will set final status at end of function
else:
logger.error(
f"Overpayment refund failed for {crypto_payment.id}: {result['error']} - will retry"
log.payment_error(
crypto_payment,
"Overpayment refund failed - will retry",
result["error"],
)
# Don't proceed to auto-sweep if refund failed - keep in overpaid status for retry
results["final_status"] = CryptoPayment.STATUS_CONFIRMED_OVERPAY
return results
else:
# Overpayment within threshold - will confirm normally at end
logger.info(f"Overpayment within 5% threshold for {crypto_payment.id}")
log.payment_info(crypto_payment, "Overpayment within 5% threshold")
else:
# Normal payment - will confirm at end
pass
# STEP 4: Auto-sweep only the invoice amount (not entire wallet) - LAST
if crypto_payment.shop_sweep_to_address:
logger.info(
f"Step 4: Auto-sweeping invoice amount for payment {crypto_payment.id}"
)
log.payment_info(crypto_payment, "Step 4: Auto-sweeping invoice amount")
# Calculate exact amount to sweep (expected invoice amount only)
coin_config = get_coin_config(crypto_payment.coin_type)
@ -619,18 +705,16 @@ def process_confirmed_payment(env_request, crypto_payment, client, payment_rescu
results["auto_sweep"] = sweep_result
if sweep_result and sweep_result.get("success"):
logger.info(
f"Invoice amount auto-sweep successful for {crypto_payment.id}: "
f"TX {sweep_result['tx_hash']}, Amount: {invoice_amount_crypto} {crypto_payment.coin_type}"
log.sweep_operation(
crypto_payment,
"successful",
sweep_result["tx_hash"],
f"{invoice_amount_crypto} {crypto_payment.coin_type}",
)
else:
logger.error(
f"Auto-sweep failed for {crypto_payment.id}: {sweep_result}"
)
log.payment_error(crypto_payment, "Auto-sweep failed", sweep_result)
else:
logger.info(
f"No shop sweep address configured for payment {crypto_payment.id}"
)
log.payment_info(crypto_payment, "No shop sweep address configured")
# STEP 5: Set terminal status ONLY at the very end when everything succeeded
if results.get("overpayment_refund") and results["overpayment_refund"].get(
@ -639,19 +723,19 @@ def process_confirmed_payment(env_request, crypto_payment, client, payment_rescu
# Overpayment refund completed successfully
crypto_payment.status = CryptoPayment.STATUS_CONFIRMED_OVERPAY_REFUNDED
results["final_status"] = CryptoPayment.STATUS_CONFIRMED_OVERPAY_REFUNDED
logger.info(
f"Payment {crypto_payment.id} fully processed - overpayment refunded and completed"
log.payment_info(
crypto_payment, "Fully processed - overpayment refunded and completed"
)
else:
# Normal payment or overpayment within threshold
crypto_payment.status = CryptoPayment.STATUS_CONFIRMED
results["final_status"] = CryptoPayment.STATUS_CONFIRMED
logger.info(f"Payment {crypto_payment.id} fully processed - confirmed")
log.payment_info(crypto_payment, "Fully processed - confirmed")
return results
except Exception as e:
logger.error(f"Error processing confirmed payment {crypto_payment.id}: {e}")
log.payment_error(crypto_payment, "Error processing confirmed payment", e)
results["error"] = str(e)
return results
@ -728,12 +812,12 @@ def auto_sweep_doge_amount(
try:
dbsession.flush()
except Exception as e:
logger.warning(f"Failed to update sweep info in database: {e}")
log.error_with_context("Failed to update sweep info in database", e)
return {"success": True, "tx_hash": tx_hash, "amount_swept": amount_to_sweep}
except Exception as e:
logger.error(f"DOGE amount sweep error for payment {crypto_payment.id}: {e}")
log.payment_error(crypto_payment, "DOGE amount sweep error", e)
return {"success": False, "error": str(e)}
@ -792,18 +876,18 @@ def auto_sweep_xmr_amount(
try:
dbsession.flush()
except Exception as e:
logger.warning(f"Failed to update sweep info in database: {e}")
log.error_with_context("Failed to update sweep info in database", e)
return {"success": True, "tx_hash": tx_hash, "amount_swept": amount_to_sweep}
except Exception as e:
logger.error(f"XMR amount sweep error for payment {crypto_payment.id}: {e}")
log.payment_error(crypto_payment, "XMR amount sweep error", e)
return {"success": False, "error": str(e)}
def auto_sweep_payment(client, crypto_payment: CryptoPayment, dbsession=None):
"""Auto-sweep funds from a confirmed payment to the shop's cold wallet."""
logger.info(f"Starting auto-sweep check for payment {crypto_payment.id}")
log.payment_info(crypto_payment, "Starting auto-sweep check")
# Dispatch to coin-specific sweep function
if crypto_payment.coin_type == "XMR":
@ -811,20 +895,23 @@ def auto_sweep_payment(client, crypto_payment: CryptoPayment, dbsession=None):
elif crypto_payment.coin_type == "DOGE":
return auto_sweep_payment_doge(client, crypto_payment, dbsession)
else:
logger.error(f"Unsupported coin type for sweep: {crypto_payment.coin_type}")
log.payment_error(
crypto_payment,
f"Unsupported coin type for sweep: {crypto_payment.coin_type}",
)
return False
def auto_sweep_payment_xmr(client, crypto_payment: CryptoPayment, dbsession=None):
"""Auto-sweep XMR funds from a confirmed payment to the shop's cold wallet."""
logger.info(f"Starting XMR auto-sweep check for payment {crypto_payment.id}")
log.payment_info(crypto_payment, "Starting XMR auto-sweep check")
if not crypto_payment.shop_sweep_to_address:
logger.info(f"Payment {crypto_payment.id} has no sweep address configured")
log.payment_info(crypto_payment, "No sweep address configured")
return False
if crypto_payment.is_swept:
logger.info(f"Payment {crypto_payment.id} already swept")
log.payment_info(crypto_payment, "Already swept")
return True
logger.info(
@ -841,8 +928,9 @@ def auto_sweep_payment_xmr(client, crypto_payment: CryptoPayment, dbsession=None
)
unlocked_balance = Decimal(result.get("unlocked_balance", 0)) / atomic_units
logger.info(
f"Account {crypto_payment.account_index} unlocked balance: {unlocked_balance} XMR"
log.payment_info(
crypto_payment,
f"Account {crypto_payment.account_index} unlocked balance: {unlocked_balance} XMR",
)
# Calculate sweep amount for THIS SPECIFIC payment only
@ -850,8 +938,9 @@ def auto_sweep_payment_xmr(client, crypto_payment: CryptoPayment, dbsession=None
# If no unlocked balance, funds are still locked (10-block lock time)
if unlocked_balance == 0:
logger.info(
f"No unlocked balance for payment {crypto_payment.id} - funds still locked, will retry later"
log.payment_info(
crypto_payment,
"No unlocked balance - funds still locked, will retry later",
)
# Don't mark as swept - funds are just locked!
return False
@ -893,8 +982,9 @@ def auto_sweep_payment_xmr(client, crypto_payment: CryptoPayment, dbsession=None
)
return False
logger.info(
f"Account has sufficient unlocked balance ({unlocked_balance} XMR) for payment amount ({payment_amount_xmr} XMR)"
log.payment_info(
crypto_payment,
f"Account has sufficient unlocked balance ({unlocked_balance} XMR) for payment amount ({payment_amount_xmr} XMR)",
)
# Verify this subaddress has the expected transfer
@ -918,12 +1008,13 @@ def auto_sweep_payment_xmr(client, crypto_payment: CryptoPayment, dbsession=None
)
return False
logger.info(
f"Found {len(transfers_result['in'])} incoming transfers for subaddress {crypto_payment.subaddress_index}"
log.payment_info(
crypto_payment,
f"Found {len(transfers_result['in'])} incoming transfers for subaddress {crypto_payment.subaddress_index}",
)
except Exception as e:
logger.error(f"Failed to verify subaddress transfers: {e}")
log.error_with_context("Failed to verify subaddress transfers", e)
return False
# Use transfer but reduce amount to account for fees
@ -956,7 +1047,9 @@ def auto_sweep_payment_xmr(client, crypto_payment: CryptoPayment, dbsession=None
except Exception as e:
# Fallback to hardcoded fee if RPC call fails
estimated_fee_piconero = int(Decimal("0.0001") * atomic_units)
logger.warning(f"Failed to get dynamic fee estimate, using fallback: {e}")
log.error_with_context(
"Failed to get dynamic fee estimate, using fallback", e
)
# Calculate transfer amount: payment minus fee and reserve for pending refunds
reserved_for_refunds_piconero = int(pending_refund_amount_xmr * atomic_units)
@ -968,8 +1061,10 @@ def auto_sweep_payment_xmr(client, crypto_payment: CryptoPayment, dbsession=None
transfer_amount_piconero = max(0, available_for_sweep)
transfer_amount_xmr = Decimal(transfer_amount_piconero) / atomic_units
logger.info(
f"Transferring {transfer_amount_xmr} XMR (payment amount minus {estimated_fee_piconero / atomic_units} XMR estimated fee and {pending_refund_amount_xmr} XMR reserved for refunds)"
log.sweep_operation(
crypto_payment,
f"transferring {transfer_amount_xmr} XMR",
amount=transfer_amount_piconero,
)
result = client._call(
@ -1003,29 +1098,29 @@ def auto_sweep_payment_xmr(client, crypto_payment: CryptoPayment, dbsession=None
crypto_payment.swept_network_fee = fee
if dbsession:
dbsession.add(crypto_payment)
logger.info(
f"Auto-sweep successful for payment {crypto_payment.id}! TX: {tx_hash}, Swept: {total_swept} atomic units, Fee: {fee} atomic units"
log.sweep_operation(
crypto_payment, "auto-sweep successful", tx_hash, total_swept
)
return True
else:
logger.error(f"Sweep failed for payment {crypto_payment.id}: {result}")
log.payment_error(crypto_payment, "Sweep failed", result)
return False
except Exception as e:
logger.error(f"Auto-sweep error for payment {crypto_payment.id}: {e}")
log.payment_error(crypto_payment, "Auto-sweep error", e)
return False
def auto_sweep_payment_doge(client, crypto_payment: CryptoPayment, dbsession=None):
"""Auto-sweep DOGE funds from a confirmed payment to the shop's cold wallet."""
logger.info(f"Starting DOGE auto-sweep check for payment {crypto_payment.id}")
log.payment_info(crypto_payment, "Starting DOGE auto-sweep check")
if not crypto_payment.shop_sweep_to_address:
logger.info(f"Payment {crypto_payment.id} has no sweep address configured")
log.payment_info(crypto_payment, "No sweep address configured")
return False
if crypto_payment.is_swept:
logger.info(f"Payment {crypto_payment.id} already swept")
log.payment_info(crypto_payment, "Already swept")
return True
logger.info(
@ -1076,7 +1171,9 @@ def auto_sweep_payment_doge(client, crypto_payment: CryptoPayment, dbsession=Non
else:
# Fallback to reasonable fee if estimatesmartfee fails
estimated_fee_doge = 0.002 # Matches quote fallback
logger.warning("estimatesmartfee failed, using fallback fee")
log.error_with_context(
"estimatesmartfee failed, using fallback fee", None
)
except Exception as e:
# Fallback to reasonable fee if RPC call fails
estimated_fee_doge = 0.002 # Matches quote fallback
@ -1143,11 +1240,11 @@ def auto_sweep_payment_doge(client, crypto_payment: CryptoPayment, dbsession=Non
)
return True
else:
logger.error(f"DOGE sweep failed for payment {crypto_payment.id}")
log.payment_error(crypto_payment, "DOGE sweep failed")
return False
except Exception as e:
logger.error(f"DOGE auto-sweep error for payment {crypto_payment.id}: {e}")
log.payment_error(crypto_payment, "DOGE auto-sweep error", e)
return False
@ -1367,6 +1464,12 @@ def finalize_invoice(env_request, crypto_payment: CryptoPayment, send_emails=Tru
tx_hash = None
if tx_hash:
log.state_transition(
crypto_payment,
crypto_payment.status,
"OUT_OF_STOCK_REFUNDED",
f"TX: {tx_hash}",
)
crypto_payment.status = CryptoPayment.STATUS_OUT_OF_STOCK_REFUNDED
crypto_payment.refund_tx_hash = tx_hash
crypto_payment.refund_amount = crypto_payment.received_amount
@ -1459,6 +1562,12 @@ def finalize_invoice(env_request, crypto_payment: CryptoPayment, send_emails=Tru
logger.error(
f"CONFIGURATION ERROR: Out of stock payment {crypto_payment.id} has no refund address and no shop sweep address"
)
log.state_transition(
crypto_payment,
crypto_payment.status,
"OUT_OF_STOCK_NOT_REFUNDED",
"no refund or sweep address",
)
crypto_payment.status = CryptoPayment.STATUS_OUT_OF_STOCK_NOT_REFUNDED
# Delete invoice for terminal state
delete_invoice_for_terminal_state(env_request.dbsession, crypto_payment)
@ -1772,8 +1881,15 @@ def process_payment(
f"Duplicate payment {crypto_payment.id} refund failed - will retry on next cycle"
)
else:
logger.error(
f"DATA ERROR: Duplicate payment {crypto_payment.id} has no invoice or user - this should not happen"
log.payment_error(
crypto_payment,
"DATA ERROR: Duplicate payment has no invoice or user - this should not happen",
)
log.state_transition(
crypto_payment,
crypto_payment.status,
"DOUBLEPAY_NOT_REFUNDED",
"no invoice or user",
)
crypto_payment.status = CryptoPayment.STATUS_DOUBLEPAY_NOT_REFUNDED
crypto_payment.refund_reason = (
@ -1801,11 +1917,20 @@ def process_payment(
# Check if refund address exists to determine final status immediately
if crypto_payment.refund_address:
crypto_payment.status = CryptoPayment.STATUS_LATEPAY_REFUNDED
logger.info(
f"Expired payment {crypto_payment.id} marked for refund (will process when confirmed)"
log.state_transition(
crypto_payment,
crypto_payment.status,
"LATEPAY_REFUNDED",
"marked for refund",
)
crypto_payment.status = CryptoPayment.STATUS_LATEPAY_REFUNDED
else:
log.state_transition(
crypto_payment,
crypto_payment.status,
"LATEPAY_NOT_REFUNDED",
"no refund address",
)
crypto_payment.status = CryptoPayment.STATUS_LATEPAY_NOT_REFUNDED
crypto_payment.refund_reason = (
"Late payment - no refund address configured"
@ -1819,6 +1944,9 @@ def process_payment(
)
else:
# No funds received - just mark as expired
log.state_transition(
crypto_payment, crypto_payment.status, "EXPIRED", "no funds received"
)
crypto_payment.status = CryptoPayment.STATUS_EXPIRED
env_request.dbsession.add(crypto_payment)
@ -2103,8 +2231,15 @@ def process_payment(
)
elif payment_rescue:
# Payment rescue available but no refund address configured
logger.warning(
f"Expired payment {crypto_payment.id} has no refund address configured - no refund possible"
log.payment_warning(
crypto_payment,
"Expired payment has no refund address configured - no refund possible",
)
log.state_transition(
crypto_payment,
crypto_payment.status,
"LATEPAY_NOT_REFUNDED",
"no refund address",
)
crypto_payment.status = CryptoPayment.STATUS_LATEPAY_NOT_REFUNDED
crypto_payment.refund_reason = (
@ -2324,10 +2459,13 @@ def process_payment(
# Update status from pending to received if this is the first amount received
if crypto_payment.status == CryptoPayment.STATUS_PENDING and new_sum > 0:
crypto_payment.status = CryptoPayment.STATUS_RECEIVED
logger.info(
f"Payment {crypto_payment.id} transitioned from pending to received with amount {crypto_payment.received_amount}"
log.state_transition(
crypto_payment,
"PENDING",
"RECEIVED",
f"amount {crypto_payment.received_amount}",
)
crypto_payment.status = CryptoPayment.STATUS_RECEIVED
# Check if original payment should move to confirmed status
if (
@ -2345,15 +2483,21 @@ def process_payment(
# Update status to confirmed
if crypto_payment.received_amount > crypto_payment.expected_amount:
log.state_transition(
crypto_payment,
"RECEIVED",
"CONFIRMED_OVERPAY",
f"received {crypto_payment.received_amount}, expected {crypto_payment.expected_amount}",
)
crypto_payment.status = CryptoPayment.STATUS_CONFIRMED_OVERPAY
logger.info(
f"Payment {crypto_payment.id} overpaid: received {crypto_payment.received_amount}, expected {crypto_payment.expected_amount}"
)
else:
crypto_payment.status = CryptoPayment.STATUS_CONFIRMED
logger.info(
f"Payment {crypto_payment.id} confirmed with {crypto_payment.current_confirmations} confirmations"
log.state_transition(
crypto_payment,
"RECEIVED",
"CONFIRMED",
f"{crypto_payment.current_confirmations} confirmations",
)
crypto_payment.status = CryptoPayment.STATUS_CONFIRMED
# Send confirmation emails if not already sent (independent of invoice finalization)
if crypto_payment.invoice and crypto_payment.invoice.user:
@ -2454,13 +2598,13 @@ def process_payment(
and crypto_payment.shop_sweep_to_address
and not crypto_payment.is_swept
):
logger.info(f"Payment {crypto_payment.id} confirmed - attempting sweep")
log.payment_info(crypto_payment, "Confirmed - attempting sweep")
try:
sweep_success = auto_sweep_payment(
client, crypto_payment, env_request.dbsession
)
if sweep_success and crypto_payment.is_swept:
logger.info(f"Payment {crypto_payment.id} swept successfully")
log.payment_info(crypto_payment, "Swept successfully")
except Exception as e:
logger.error(
f"Auto-sweep failed for confirmed payment {crypto_payment.id}: {e}"
@ -2593,6 +2737,12 @@ def process_payment(
# Check if refund address is available
if crypto_payment.refund_address:
# Set status immediately to get out of active queue
log.state_transition(
crypto_payment,
crypto_payment.status,
"UNDERPAID_REFUNDED",
f"received {received_xmr}, expected {expected_xmr}",
)
crypto_payment.status = CryptoPayment.STATUS_UNDERPAID_REFUNDED
crypto_payment.refund_reason = f"Underpayment: received {received_xmr} but expected {expected_xmr}"
@ -2642,6 +2792,12 @@ def process_payment(
logger.warning(
f"Underpayment {crypto_payment.id} has no refund address configured - marking as no-refund"
)
log.state_transition(
crypto_payment,
crypto_payment.status,
"UNDERPAID_NOT_REFUNDED",
"no refund address",
)
crypto_payment.status = CryptoPayment.STATUS_UNDERPAID_NOT_REFUNDED
crypto_payment.refund_reason = (
"Underpayment - no refund address configured"
@ -2769,7 +2925,7 @@ def process_refund_confirmations(request, settings):
Monitor refund transactions for confirmation status.
Updates refund_confirmations and transitions status when fully confirmed.
"""
logger.info("Starting refund confirmation monitoring")
log.processing_cycle("Starting refund confirmation monitoring")
db = request.dbsession
@ -2791,10 +2947,10 @@ def process_refund_confirmations(request, settings):
)
if not refund_queue:
logger.debug("No refund transactions need confirmation monitoring")
log.processing_cycle("No refund transactions need confirmation monitoring")
return
logger.info(f"Found {len(refund_queue)} refund transactions to monitor")
log.processing_cycle("Found refund transactions to monitor", len(refund_queue))
# Group by coin type to get appropriate clients
refunds_by_coin = {}
@ -2806,12 +2962,16 @@ def process_refund_confirmations(request, settings):
# Process each coin type
for coin_type, coin_refunds in refunds_by_coin.items():
logger.info(f"Monitoring {len(coin_refunds)} {coin_type} refund transactions")
log.processing_cycle(
f"Monitoring {coin_type} refund transactions", len(coin_refunds)
)
try:
client = get_crypto_client(settings, coin_type)
except ValueError as e:
logger.error(f"Failed to get {coin_type} client for refund monitoring: {e}")
log.error_with_context(
f"Failed to get {coin_type} client for refund monitoring", e
)
continue
for payment in coin_refunds:
@ -2828,8 +2988,9 @@ def process_refund_confirmations(request, settings):
"confirmations_required", 10
) # Default to 10 if not specified
if payment.current_confirmations >= required_confirmations:
logger.info(
f"Retrying refund for payment {payment.id} - now has {payment.current_confirmations} confirmations"
log.payment_info(
payment,
f"Retrying refund - now has {payment.current_confirmations} confirmations",
)
# Retry the refund process (import payment rescue here to avoid circular imports)
@ -2909,9 +3070,7 @@ def process_refund_confirmations(request, settings):
payment.refund_confirmations = confirmations
if confirmations != old_confirmations:
logger.info(
f"REFUND transaction confirmations for payment {payment.id}: {old_confirmations}{confirmations} (TX: {payment.refund_tx_hash[:16]}...) [incoming: {payment.current_confirmations}]"
)
log.confirmation_update(payment, old_confirmations, confirmations)
# Check if refund is now fully confirmed (10+ confirmations)
if confirmations >= 10:
@ -2922,8 +3081,11 @@ def process_refund_confirmations(request, settings):
payment.status = (
CryptoPayment.STATUS_CONFIRMED_OVERPAY_REFUNDED_COMPLETE
)
logger.info(
f"REFUND FULLY CONFIRMED - Overpayment refund for payment {payment.id}: {old_status}{payment.status} (refund TX: {payment.refund_tx_hash[:16]}... with {confirmations} confirmations)"
log.state_transition(
payment,
old_status,
payment.status,
f"refund confirmed with {confirmations} confirmations",
)
# Sweep remaining funds (restocking fee) to shop
sweep_restocking_fee(
@ -2940,8 +3102,11 @@ def process_refund_confirmations(request, settings):
payment.status = (
CryptoPayment.STATUS_CONFIRMED_OVERPAY_REFUNDED_COMPLETE
)
logger.info(
f"REFUND FULLY CONFIRMED - Overpayment refund for payment {payment.id}: {old_status}{payment.status} (refund TX: {payment.refund_tx_hash[:16]}... with {confirmations} confirmations)"
log.state_transition(
payment,
old_status,
payment.status,
f"refund confirmed with {confirmations} confirmations",
)
# Sweep remaining funds (restocking fee) to shop
sweep_restocking_fee(
@ -2955,8 +3120,11 @@ def process_refund_confirmations(request, settings):
payment.status = CryptoPayment.STATUS_LATEPAY_REFUNDED_COMPLETE
# Delete invoice for terminal state
delete_invoice_for_terminal_state(db, payment)
logger.info(
f"REFUND FULLY CONFIRMED - Expired refund for payment {payment.id}: {old_status}{payment.status} (refund TX: {payment.refund_tx_hash[:16]}... with {confirmations} confirmations)"
log.state_transition(
payment,
old_status,
payment.status,
f"refund confirmed with {confirmations} confirmations",
)
# Sweep remaining funds (restocking fee) to shop
sweep_restocking_fee(
@ -2972,8 +3140,11 @@ def process_refund_confirmations(request, settings):
)
# Delete invoice for terminal state
delete_invoice_for_terminal_state(db, payment)
logger.info(
f"REFUND FULLY CONFIRMED - Underpaid refund for payment {payment.id}: {old_status}{payment.status} (refund TX: {payment.refund_tx_hash[:16]}... with {confirmations} confirmations)"
log.state_transition(
payment,
old_status,
payment.status,
f"refund confirmed with {confirmations} confirmations",
)
# Sweep remaining funds (restocking fee) to shop
sweep_restocking_fee(
@ -2989,14 +3160,22 @@ def process_refund_confirmations(request, settings):
)
# Delete invoice for terminal state
delete_invoice_for_terminal_state(db, payment)
logger.info(
f"REFUND FULLY CONFIRMED - Out-of-stock refund for payment {payment.id}: {old_status}{payment.status} (refund TX: {payment.refund_tx_hash[:16]}... with {confirmations} confirmations)"
log.state_transition(
payment,
old_status,
payment.status,
f"refund confirmed with {confirmations} confirmations",
)
elif payment.status == CryptoPayment.STATUS_DOUBLEPAY_REFUNDED:
payment.status = CryptoPayment.STATUS_DOUBLEPAY_REFUNDED_COMPLETE
payment.status = (
CryptoPayment.STATUS_DOUBLEPAY_REFUNDED_COMPLETE
)
# No invoice to delete - duplicate payments don't have invoices
logger.info(
f"REFUND FULLY CONFIRMED - Double payment refund for payment {payment.id}: {old_status}{payment.status} (refund TX: {payment.refund_tx_hash[:16]}... with {confirmations} confirmations)"
log.state_transition(
payment,
old_status,
payment.status,
f"refund confirmed with {confirmations} confirmations",
)
# Sweep remaining funds (restocking fee) to shop
sweep_restocking_fee(
@ -3017,9 +3196,7 @@ def process_refund_confirmations(request, settings):
db.add(payment)
except Exception as e:
logger.error(
f"Failed to check refund confirmations for payment {payment.id}: {e}"
)
log.payment_error(payment, "Failed to check refund confirmations", e)
continue
@ -3108,7 +3285,7 @@ def update_payment_confirmations_only(client, crypto_payment, coin_type):
try:
stored_txids = json.loads(crypto_payment.tx_hashes or "[]")
if not stored_txids:
logger.debug(f"No tx_hashes for payment {crypto_payment.id}")
log.payment_debug(crypto_payment, "No tx_hashes")
return
# Get confirmation count for all transactions
@ -3154,7 +3331,7 @@ def scan_wallet_for_double_or_late_payments(request, settings):
2. Late payments to expired/cancelled quotes that aren't actively monitored
Uses scan position tracking to avoid rescanning old transfers.
"""
logger.info("Starting wallet scan for double or late payments")
log.processing_cycle("Starting wallet scan for double or late payments")
db = request.dbsession
# Import here to avoid circular imports
@ -3164,10 +3341,10 @@ def scan_wallet_for_double_or_late_payments(request, settings):
processors = db.query(CryptoProcessor).filter(CryptoProcessor.enabled == True).all()
if not processors:
logger.debug("No active crypto processors found for scanning")
log.processing_cycle("No active crypto processors found for scanning")
return
logger.info(f"Found {len(processors)} active crypto processors to scan")
log.processing_cycle("Found processors to scan", len(processors))
# Group processors by coin type for efficient scanning
processors_by_coin = {}
@ -3602,14 +3779,16 @@ def run_once(env, interval):
request = env["request"]
settings = request.registry.settings
logger.info("Crypto watcher starting payment processing cycle")
log.processing_cycle("Starting payment processing cycle")
# First, do passive scan for late payments to expired/cancelled quotes
with request.tm:
try:
scan_wallet_for_double_or_late_payments(request, settings)
except Exception as e:
logger.error(f"Failed to scan wallet for double or late payments: {e}")
log.error_with_context(
"Failed to scan wallet for double or late payments", e
)
with request.tm:
db = request.dbsession
@ -3645,7 +3824,7 @@ def run_once(env, interval):
# Process each coin type separately
for coin_type, coin_payments in payments_by_coin.items():
logger.info(f"Processing {len(coin_payments)} {coin_type} payments")
log.processing_cycle(f"Processing {coin_type} payments", len(coin_payments))
try:
client = get_crypto_client(settings, coin_type)
@ -3801,12 +3980,12 @@ def main(argv=sys.argv):
while True:
run_once(env, args.interval)
if args.once:
logger.info("Crypto watcher finished single run")
log.processing_cycle("Finished single run")
break
logger.info(f"Crypto watcher sleeping for {args.interval} seconds")
log.processing_cycle(f"Sleeping for {args.interval} seconds")
time.sleep(args.interval)
finally:
logger.info("Crypto watcher shutting down")
log.processing_cycle("Shutting down")
env["closer"]()

View file

@ -532,3 +532,158 @@ class CryptoPayment(RBase, Base):
bool: True if payment is in initial/waiting state, False otherwise
"""
return self.status in self.INITIAL_WAITING_STATUSES
def __str__(self) -> str:
"""
Human-readable string representation for logging and debugging.
Returns:
str: Concise payment description for logs
"""
return self._format_payment_summary()
def __repr__(self) -> str:
"""
Developer-oriented string representation for debugging.
Returns:
str: Detailed payment description for debugging
"""
return (
f"CryptoPayment(id={self.uuid_str[:8]}, "
f"status={self.status}, "
f"coin={self.coin_type}, "
f"expected={self.expected_amount}, "
f"received={self.received_amount}, "
f"confirmations={self.current_confirmations or 0}/{self.confirmations_required}, "
f"invoice_id={self.invoice_id.hex[:8] if self.invoice_id else None})"
)
def _format_payment_summary(self) -> str:
"""
Format payment as a concise summary for logging.
Returns:
str: Payment summary with key details
"""
# Get amount information
if self.coin_type == "XMR":
expected_display = f"{self.expected_amount / 1e12:.6f}"
received_display = f"{self.received_amount / 1e12:.6f}"
elif self.coin_type == "DOGE":
expected_display = f"{self.expected_amount / 1e8:.8f}"
received_display = f"{self.received_amount / 1e8:.8f}"
else: # BTC, LTC, BCH
expected_display = f"{self.expected_amount / 1e8:.8f}"
received_display = f"{self.received_amount / 1e8:.8f}"
# Build status description
status_desc = self._get_status_description()
# Format confirmations
conf_desc = f"{self.current_confirmations or 0}/{self.confirmations_required}"
# Get user display name if available
user_display = ""
if self.user and hasattr(self.user, "display_name") and self.user.display_name:
user_display = f" user:{self.user.display_name}"
elif self.user and hasattr(self.user, "username") and self.user.username:
user_display = f" user:{self.user.username}"
# Get shop name if available
shop_display = ""
if self.shop and hasattr(self.shop, "name") and self.shop.name:
shop_display = f" shop:{self.shop.name}"
return (
f"Payment {self.uuid_str[:8]} [{status_desc}] "
f"{self.coin_type} {received_display}/{expected_display} "
f"conf:{conf_desc} addr:{self.address[-8:]}{user_display}{shop_display}"
)
def _get_status_description(self) -> str:
"""
Get human-readable status description for logging.
Returns:
str: Human-readable status description
"""
status_descriptions = {
# Initial/waiting states
self.STATUS_PENDING: "waiting",
# Active processing states
self.STATUS_RECEIVED: "received",
self.STATUS_CONFIRMED: "confirmed",
self.STATUS_CONFIRMED_OVERPAY: "overpaid",
# Refund processing states
self.STATUS_CONFIRMED_OVERPAY_REFUNDED: "overpay-refunding",
self.STATUS_LATEPAY_REFUNDED: "late-refunding",
self.STATUS_UNDERPAID_REFUNDED: "underpay-refunding",
self.STATUS_OUT_OF_STOCK_REFUNDED: "oos-refunding",
self.STATUS_DOUBLEPAY_REFUNDED: "duplicate-refunding",
# Completed refund states
self.STATUS_CONFIRMED_OVERPAY_REFUNDED_COMPLETE: "overpay-refunded",
self.STATUS_LATEPAY_REFUNDED_COMPLETE: "late-refunded",
self.STATUS_UNDERPAID_REFUNDED_COMPLETE: "underpay-refunded",
self.STATUS_OUT_OF_STOCK_REFUNDED_COMPLETE: "oos-refunded",
self.STATUS_DOUBLEPAY_REFUNDED_COMPLETE: "duplicate-refunded",
# No-refund states
self.STATUS_CONFIRMED_OVERPAY_NOT_REFUNDED: "overpay-no-refund",
self.STATUS_LATEPAY_NOT_REFUNDED: "late-no-refund",
self.STATUS_UNDERPAID_NOT_REFUNDED: "underpay-no-refund",
self.STATUS_OUT_OF_STOCK_NOT_REFUNDED: "oos-no-refund",
self.STATUS_DOUBLEPAY_NOT_REFUNDED: "duplicate-no-refund",
# Terminal states
self.STATUS_EXPIRED: "expired",
self.STATUS_CANCELLED: "cancelled",
}
return status_descriptions.get(self.status, self.status)
def format_transaction_log(self, context: str = "") -> str:
"""
Format payment for transaction logging with optional context.
Args:
context: Optional context (e.g., "processing", "refunding")
Returns:
str: Formatted transaction log entry
"""
base_msg = str(self)
if context:
return f"{context.capitalize()}: {base_msg}"
return base_msg
def format_amount_details(self) -> str:
"""
Format detailed amount information for logging.
Returns:
str: Detailed amount breakdown
"""
if self.coin_type == "XMR":
expected = f"{self.expected_amount / 1e12:.6f}"
received = f"{self.received_amount / 1e12:.6f}"
due = f"{self.due_amount / 1e12:.6f}" if self.due_amount > 0 else "0"
elif self.coin_type == "DOGE":
expected = f"{self.expected_amount / 1e8:.8f}"
received = f"{self.received_amount / 1e8:.8f}"
due = f"{self.due_amount / 1e8:.8f}" if self.due_amount > 0 else "0"
else: # BTC, LTC, BCH
expected = f"{self.expected_amount / 1e8:.8f}"
received = f"{self.received_amount / 1e8:.8f}"
due = f"{self.due_amount / 1e8:.8f}" if self.due_amount > 0 else "0"
return f"expected:{expected} received:{received} due:{due} {self.coin_type}"
def format_confirmation_status(self) -> str:
"""
Format confirmation status for logging.
Returns:
str: Confirmation status description
"""
status = "confirmed" if self.is_fully_confirmed else "pending"
current = self.current_confirmations or 0
return f"{status} ({current}/{self.confirmations_required})"

View file

@ -774,7 +774,9 @@ class TestCryptoPaymentTransitions(unittest.TestCase):
payment.status = CryptoPayment.STATUS_DOUBLEPAY_REFUNDED
self.assertTrue(
payment.is_valid_transition(CryptoPayment.STATUS_DOUBLEPAY_REFUNDED_COMPLETE)
payment.is_valid_transition(
CryptoPayment.STATUS_DOUBLEPAY_REFUNDED_COMPLETE
)
)

View file

@ -430,7 +430,9 @@ class TestDoubleSpendIntegration(DatabaseIntegrationTests):
p for p in all_payments if p.status == CryptoPayment.STATUS_CONFIRMED
]
duplicate_payments = [
p for p in all_payments if p.status == CryptoPayment.STATUS_DOUBLEPAY_REFUNDED
p
for p in all_payments
if p.status == CryptoPayment.STATUS_DOUBLEPAY_REFUNDED
]
# Verify counts

View file

@ -110,7 +110,9 @@ class InvoiceDeletionIntegrationTests(DatabaseIntegrationTests):
def test_expired_payment_deletes_invoice(self):
"""Test that expired payments have their invoices deleted."""
payment, invoice = self.create_crypto_payment_with_invoice(CryptoPayment.STATUS_EXPIRED)
payment, invoice = self.create_crypto_payment_with_invoice(
CryptoPayment.STATUS_EXPIRED
)
invoice_id = invoice.id
payment_id = payment.id
@ -139,7 +141,9 @@ class InvoiceDeletionIntegrationTests(DatabaseIntegrationTests):
def test_cancelled_payment_deletes_invoice(self):
"""Test that cancelled payments have their invoices deleted."""
payment, invoice = self.create_crypto_payment_with_invoice(CryptoPayment.STATUS_CANCELLED)
payment, invoice = self.create_crypto_payment_with_invoice(
CryptoPayment.STATUS_CANCELLED
)
invoice_id = invoice.id
@ -153,7 +157,9 @@ class InvoiceDeletionIntegrationTests(DatabaseIntegrationTests):
def test_no_refund_payment_deletes_invoice(self):
"""Test that no-refund payments have their invoices deleted."""
payment, invoice = self.create_crypto_payment_with_invoice(CryptoPayment.STATUS_LATEPAY_NOT_REFUNDED)
payment, invoice = self.create_crypto_payment_with_invoice(
CryptoPayment.STATUS_LATEPAY_NOT_REFUNDED
)
invoice_id = invoice.id
@ -189,7 +195,9 @@ class InvoiceDeletionIntegrationTests(DatabaseIntegrationTests):
def test_confirmed_payment_keeps_invoice(self):
"""Test that confirmed payments keep their invoices."""
payment, invoice = self.create_crypto_payment_with_invoice(CryptoPayment.STATUS_CONFIRMED)
payment, invoice = self.create_crypto_payment_with_invoice(
CryptoPayment.STATUS_CONFIRMED
)
invoice_id = invoice.id
payment_id = payment.id
@ -211,7 +219,9 @@ class InvoiceDeletionIntegrationTests(DatabaseIntegrationTests):
def test_confirmed_overpaid_payment_keeps_invoice(self):
"""Test that confirmed-overpaid payments keep their invoices."""
payment, invoice = self.create_crypto_payment_with_invoice(CryptoPayment.STATUS_CONFIRMED_OVERPAY)
payment, invoice = self.create_crypto_payment_with_invoice(
CryptoPayment.STATUS_CONFIRMED_OVERPAY
)
invoice_id = invoice.id
@ -296,7 +306,9 @@ class InvoiceDeletionIntegrationTests(DatabaseIntegrationTests):
def test_state_transition_triggers_invoice_deletion(self):
"""Test that changing payment state to terminal triggers invoice deletion."""
payment, invoice = self.create_crypto_payment_with_invoice(CryptoPayment.STATUS_PENDING)
payment, invoice = self.create_crypto_payment_with_invoice(
CryptoPayment.STATUS_PENDING
)
invoice_id = invoice.id

View file

@ -4,6 +4,8 @@ import uuid
import mock
from ..models import User, Coupon, Shop, is_user_name_valid
from ..models.crypto_payment import CryptoPayment
from ..models.invoice import Invoice
from ..models.meta import now_timestamp, short_id_to_bytes, id_to_uuid
mock_always_none = mock.Mock(return_value=None)
@ -1372,3 +1374,218 @@ class TestUserCryptoRefundAddress(unittest.TestCase):
mock_session, self.user, self.shop, "XMR"
)
self.assertEqual(result, expected_addr)
class TestCryptoPayment(unittest.TestCase):
"""Unit tests for CryptoPayment model string representation methods."""
@mock.patch("make_post_sell.models.user.is_user_name_available", mock_always_true)
def setUp(self):
"""Set up test fixtures."""
self.user = User("alice@example.com")
self.user.display_name = "Alice"
self.shop = Shop(
name="Alice's Shop",
phone_number="555-1234",
billing_address="123 Main St",
description="Test shop",
)
# Create test payment without invoice for simpler testing
self.payment = CryptoPayment(
invoice=None, # Skip invoice relationship for unit tests
user=self.user,
shop=self.shop,
address="44AFFq5kSiGBoZ4NMDwYtN18obc8AemS33DBLWs3H7otXft3XjrpDtQGv7SqSsaBYBb98uNbr2VBBEt7f2wfn3RVGQBEP3A",
account_index=0,
subaddress_index=1,
coin_type="XMR",
expected_amount=1000000000000, # 1.0 XMR in piconero
rate_locked_usd_per_coin=150.00,
quote_expires_at_ms=now_timestamp() + 3600000, # 1 hour from now
confirmations_required=10,
)
def test_str_basic_pending_payment(self):
"""Test __str__ for basic pending payment."""
result = str(self.payment)
# Should include payment ID, status, coin type, amounts, confirmations, address, user, shop
self.assertIn(self.payment.uuid_str[:8], result)
self.assertIn("[waiting]", result) # pending status description
self.assertIn("XMR", result)
self.assertIn("0.000000/1.000000", result) # received/expected in XMR
self.assertIn("conf:0/10", result)
self.assertIn("addr:", result)
self.assertIn("user:Alice", result)
self.assertIn("shop:Alice's Shop", result)
def test_str_received_payment_with_confirmations(self):
"""Test __str__ for received payment with some confirmations."""
self.payment.status = CryptoPayment.STATUS_RECEIVED
self.payment.received_amount = 800000000000 # 0.8 XMR
self.payment.current_confirmations = 5
result = str(self.payment)
self.assertIn("[received]", result)
self.assertIn("0.800000/1.000000", result)
self.assertIn("conf:5/10", result)
def test_str_confirmed_overpayment(self):
"""Test __str__ for confirmed overpayment."""
self.payment.status = CryptoPayment.STATUS_CONFIRMED_OVERPAY
self.payment.received_amount = 1200000000000 # 1.2 XMR
self.payment.current_confirmations = 12
result = str(self.payment)
self.assertIn("[overpaid]", result)
self.assertIn("1.200000/1.000000", result)
self.assertIn("conf:12/10", result)
def test_str_dogecoin_precision(self):
"""Test __str__ with DOGE amounts (8 decimal places)."""
self.payment.coin_type = "DOGE"
self.payment.expected_amount = 100000000000 # 1000.0 DOGE in satoshis
self.payment.received_amount = 95000000000 # 950.0 DOGE
result = str(self.payment)
self.assertIn("DOGE", result)
self.assertIn("950.00000000/1000.00000000", result)
def test_str_no_user_display_name_fallback_to_username(self):
"""Test __str__ falls back to username when no display_name."""
self.user.display_name = None
self.user.username = "alice_user"
result = str(self.payment)
self.assertIn("user:alice_user", result)
self.assertNotIn("user:Alice", result)
def test_str_no_user_info(self):
"""Test __str__ when user has no display name or username."""
self.user.display_name = None
self.user.username = None
result = str(self.payment)
# Should not include user info but should still include shop
self.assertNotIn("user:", result)
self.assertIn("shop:Alice's Shop", result)
def test_str_no_shop_name(self):
"""Test __str__ when shop has no name."""
self.shop.name = None
result = str(self.payment)
# Should not include shop info but should still include user
self.assertNotIn("shop:", result)
self.assertIn("user:Alice", result)
def test_repr_method(self):
"""Test __repr__ method for debugging."""
result = repr(self.payment)
self.assertIn("CryptoPayment(", result)
self.assertIn(f"id={self.payment.uuid_str[:8]}", result)
self.assertIn("status=pending", result)
self.assertIn("coin=XMR", result)
self.assertIn("expected=1000000000000", result)
self.assertIn("received=0", result)
self.assertIn("confirmations=0/10", result) # Should show 0 due to our fix
def test_get_status_description_all_statuses(self):
"""Test _get_status_description for all status types."""
status_mapping = {
CryptoPayment.STATUS_PENDING: "waiting",
CryptoPayment.STATUS_RECEIVED: "received",
CryptoPayment.STATUS_CONFIRMED: "confirmed",
CryptoPayment.STATUS_CONFIRMED_OVERPAY: "overpaid",
CryptoPayment.STATUS_EXPIRED: "expired",
CryptoPayment.STATUS_CANCELLED: "cancelled",
CryptoPayment.STATUS_LATEPAY_REFUNDED: "late-refunding",
CryptoPayment.STATUS_UNDERPAID_REFUNDED: "underpay-refunding",
CryptoPayment.STATUS_DOUBLEPAY_REFUNDED: "duplicate-refunding",
CryptoPayment.STATUS_LATEPAY_REFUNDED_COMPLETE: "late-refunded",
CryptoPayment.STATUS_UNDERPAID_REFUNDED_COMPLETE: "underpay-refunded",
CryptoPayment.STATUS_DOUBLEPAY_REFUNDED_COMPLETE: "duplicate-refunded",
CryptoPayment.STATUS_LATEPAY_NOT_REFUNDED: "late-no-refund",
CryptoPayment.STATUS_UNDERPAID_NOT_REFUNDED: "underpay-no-refund",
CryptoPayment.STATUS_DOUBLEPAY_NOT_REFUNDED: "duplicate-no-refund",
}
for status, expected_desc in status_mapping.items():
self.payment.status = status
result = self.payment._get_status_description()
self.assertEqual(
result, expected_desc, f"Status {status} should map to {expected_desc}"
)
def test_format_transaction_log_with_context(self):
"""Test format_transaction_log method with context."""
self.payment.status = CryptoPayment.STATUS_RECEIVED
result = self.payment.format_transaction_log("processing")
self.assertIn("Processing:", result)
self.assertIn("[received]", result)
def test_format_transaction_log_without_context(self):
"""Test format_transaction_log method without context."""
result = self.payment.format_transaction_log()
# Should be same as str() when no context
self.assertEqual(result, str(self.payment))
def test_format_amount_details_xmr(self):
"""Test format_amount_details for XMR."""
self.payment.received_amount = 800000000000 # 0.8 XMR
result = self.payment.format_amount_details()
self.assertIn("expected:1.000000", result)
self.assertIn("received:0.800000", result)
self.assertIn("due:0.200000", result)
self.assertIn("XMR", result)
def test_format_amount_details_doge(self):
"""Test format_amount_details for DOGE."""
self.payment.coin_type = "DOGE"
self.payment.expected_amount = 100000000000 # 1000.0 DOGE
self.payment.received_amount = 95000000000 # 950.0 DOGE
result = self.payment.format_amount_details()
self.assertIn("expected:1000.00000000", result)
self.assertIn("received:950.00000000", result)
self.assertIn("due:50.00000000", result)
self.assertIn("DOGE", result)
def test_format_amount_details_no_due_amount(self):
"""Test format_amount_details when fully paid."""
self.payment.received_amount = 1000000000000 # 1.0 XMR - exactly expected
result = self.payment.format_amount_details()
self.assertIn("due:0", result)
def test_format_confirmation_status_pending(self):
"""Test format_confirmation_status for pending confirmations."""
self.payment.current_confirmations = 5
result = self.payment.format_confirmation_status()
self.assertEqual(result, "pending (5/10)")
def test_format_confirmation_status_confirmed(self):
"""Test format_confirmation_status for fully confirmed."""
self.payment.current_confirmations = 15 # More than required
result = self.payment.format_confirmation_status()
self.assertEqual(result, "confirmed (15/10)")

View file

@ -55,7 +55,7 @@ def crypto_processor_settings(request):
request.session.flash(
(
f"Cannot remove {coin_type} cold wallet address. You can only replace it with a new address or disable {coin_type} payments.",
"error"
"error",
)
)
return HTTPFound(f"/s/{shop.id}/settings")