Merge pull request #81 from Routstr/main

push prod

.env.example

@@ -44,7 +44,5 @@ HTTP_URL=""
 # Not used currently
 ONION_URL="XXX.onion"
 
-RELAYS="wss://relay.damus.io,wss://relay.primal.net,wss://relay.snort.social,wss://relay.nostr.band"
+RELAYS="wss://relay.damus.io,wss://relay.nostr.band"
 CASHU_MINTS="https://mint.minibits.cash/Bitcoin,https://mint.cubabitcoin.org"
-
-CURRENCY = ""

.gitignore

@@ -15,5 +15,10 @@ compose.override.yml
 # Coverage
 .coverage
 
-# deployment
+# Logging
+logs/*
+!logs/.gitkeep
 *.log
+
+# deployment
+proof_backups

Dockerfile

@@ -13,7 +13,8 @@ RUN apk add git
 
 COPY uv.lock pyproject.toml ./
 
-RUN uv sync
+RUN uv add git+https://github.com/saschanaz/secp256k1-py.git#branch=upgrade060
+# RUN uv sync
 
 WORKDIR /app
 

README.md

@@ -84,6 +84,10 @@ The most common settings are shown below. See `.env.example` for the full list.
 - `REFUND_PROCESSING_INTERVAL` – Seconds between automatic refunds
 - `ADMIN_PASSWORD` – Password for the `/admin` dashboard
 
+## Withdrawing Balance
+
+Go to `https://<your.routstr.proxy>/admin/` (NOTE: be sure to add the '/' at the end), enter the `ADMIN_PASSWORD` you set above and withdraw your balance as a Cashu token. 
+
 ## Example Client
 
 `example.py` shows how to use the proxy with the official OpenAI client:

compose.yml

@@ -5,6 +5,7 @@ services:
     build: .
     volumes:
       - .:/app
+      - ./logs:/app/logs
     env_file:
       - .env
     environment:

pyproject.toml

@@ -7,10 +7,13 @@ requires-python = ">=3.11"
 dependencies = [
     "fastapi[standard]>=0.115",
     "aiosqlite>=0.20",
-    "sixty-nuts>=0.1.3",
     "sqlmodel>=0.0.24",
     "httpx[socks]>=0.25.2",
     "greenlet>=3.2.1",
+    "python-json-logger>=2.0.0",
+    "cashu",
+    "secp256k1",
+    "marshmallow>=3.13,<4.0",
 ]
 
 [dependency-groups]
@@ -57,3 +60,6 @@ check_untyped_defs = true
 disallow_untyped_calls = true
 disallow_incomplete_defs = true
 disallow_untyped_decorators = true
+
+[tool.uv.sources]
+secp256k1 = { git = "https://github.com/saschanaz/secp256k1-py", branch = "upgrade060" }

router/account.py

@@ -3,13 +3,8 @@ from typing import Annotated, NoReturn
 from fastapi import APIRouter, Depends, Header, HTTPException
 
 from .auth import validate_bearer_key
-from .cashu import (
-    credit_balance,
-    delete_key_if_zero_balance,
-    refund_balance,
-    wallet,
-)
 from .db import ApiKey, AsyncSession, get_session
+from .wallet import credit_balance, send_to_lnurl, send_token
 
 wallet_router = APIRouter(prefix="/v1/wallet")
 
@@ -66,8 +61,8 @@ async def refund_wallet_endpoint(
 
     # Perform refund operation first, before modifying balance
     if key.refund_address:
-        await refund_balance(remaining_balance_msats, key, session)
-        result = {"recipient": key.refund_address, "msats": remaining_balance_msats}
+        await send_to_lnurl(remaining_balance_msats, "msat", key.refund_address)
+        result = {"recipient": key.refund_address, "msat": remaining_balance_msats}
     else:
         # Convert msats to sats for cashu wallet
         remaining_balance_sats = remaining_balance_msats // 1000
@@ -76,15 +71,13 @@ async def refund_wallet_endpoint(
                 status_code=400, detail="Balance too small to refund (less than 1 sat)"
             )
 
-        token = await wallet().send(remaining_balance_sats)
+        # TODO: choose currency and mint based on what user has configured
+        token = await send_token(remaining_balance_sats, "sat")
 
         result = {"msats": remaining_balance_msats, "recipient": None, "token": token}
 
-    # Only after successful refund, zero out the balance
-    key.balance = 0
-    session.add(key)
+    await session.delete(key)
     await session.commit()
-    await delete_key_if_zero_balance(key, session)
 
     return result
 

router/admin.py

@@ -1,16 +1,21 @@
 import os
 from datetime import datetime, timezone
 
-from fastapi import APIRouter, Request
+from fastapi import APIRouter, HTTPException, Request
 from fastapi.responses import HTMLResponse
+from pydantic import BaseModel
 from sqlmodel import select
 
-from .cashu import wallet
 from .db import ApiKey, create_session
+from .wallet import get_balance, send_token
 
 admin_router = APIRouter(prefix="/admin")
 
 
+class WithdrawRequest(BaseModel):
+    amount: int
+
+
 def login_form() -> str:
     return """<!DOCTYPE html>
     <html>
@@ -112,7 +117,7 @@ async def dashboard(request: Request) -> str:
     # avoid rounding issues.
     total_user_balance = sum(key.balance for key in api_keys) // 1000
     # Fetch balance from cashu
-    current_balance = await wallet().get_balance()
+    current_balance = await get_balance("sat")
     owner_balance = current_balance - total_user_balance
 
     return f"""<!DOCTYPE html>
@@ -128,7 +133,192 @@ async def dashboard(request: Request) -> str:
                     padding: 8px;
                     text-align: left;
                 }}
+                button {{
+                    padding: 8px 16px;
+                    cursor: pointer;
+                    background-color: #007bff;
+                    color: white;
+                    border: none;
+                    border-radius: 4px;
+                    margin-right: 10px;
+                }}
+                button:hover {{
+                    background-color: #0056b3;
+                }}
+                button:disabled {{
+                    background-color: #6c757d;
+                    cursor: not-allowed;
+                }}
+                #token-result {{
+                    margin-top: 20px;
+                    padding: 15px;
+                    background-color: #f8f9fa;
+                    border: 1px solid #dee2e6;
+                    border-radius: 4px;
+                    word-break: break-all;
+                    display: none;
+                    max-width: 100%;
+                }}
+                #token-text {{
+                    font-family: monospace;
+                    font-size: 12px;
+                    background-color: #e9ecef;
+                    padding: 10px;
+                    border-radius: 4px;
+                    margin: 10px 0;
+                }}
+                .copy-btn {{
+                    background-color: #28a745;
+                    padding: 4px 8px;
+                    font-size: 12px;
+                }}
+                .copy-btn:hover {{
+                    background-color: #1e7e34;
+                }}
+                .refresh-btn {{
+                    background-color: #ffc107;
+                    color: black;
+                }}
+                .refresh-btn:hover {{
+                    background-color: #e0a800;
+                }}
+                .modal {{
+                    display: none;
+                    position: fixed;
+                    z-index: 1;
+                    left: 0;
+                    top: 0;
+                    width: 100%;
+                    height: 100%;
+                    background-color: rgba(0,0,0,0.4);
+                }}
+                .modal-content {{
+                    background-color: #fefefe;
+                    margin: 15% auto;
+                    padding: 20px;
+                    border: 1px solid #888;
+                    width: 300px;
+                    border-radius: 8px;
+                    text-align: center;
+                }}
+                .close {{
+                    color: #aaa;
+                    float: right;
+                    font-size: 28px;
+                    font-weight: bold;
+                    cursor: pointer;
+                }}
+                .close:hover {{
+                    color: black;
+                }}
+                input[type="number"] {{
+                    width: 100%;
+                    padding: 8px;
+                    margin: 10px 0;
+                    border: 1px solid #ddd;
+                    border-radius: 4px;
+                }}
+                .warning {{
+                    color: #dc3545;
+                    font-weight: bold;
+                    margin: 10px 0;
+                }}
             </style>
+            <script>
+                function openWithdrawModal() {{
+                    const modal = document.getElementById('withdraw-modal');
+                    const amountInput = document.getElementById('withdraw-amount');
+                    amountInput.value = {owner_balance};
+                    modal.style.display = 'block';
+                }}
+
+                function closeWithdrawModal() {{
+                    const modal = document.getElementById('withdraw-modal');
+                    modal.style.display = 'none';
+                }}
+
+                function checkAmount() {{
+                    const amount = parseInt(document.getElementById('withdraw-amount').value);
+                    const warning = document.getElementById('withdraw-warning');
+                    const ownerBalance = {owner_balance};
+                    
+                    if (amount > ownerBalance && amount <= {current_balance}) {{
+                        warning.style.display = 'block';
+                    }} else {{
+                        warning.style.display = 'none';
+                    }}
+                }}
+
+                async function performWithdraw() {{
+                    const amount = parseInt(document.getElementById('withdraw-amount').value);
+                    const button = document.getElementById('confirm-withdraw-btn');
+                    const tokenResult = document.getElementById('token-result');
+                    
+                    if (!amount || amount <= 0) {{
+                        alert('Please enter a valid amount');
+                        return;
+                    }}
+                    
+                    if (amount > {current_balance}) {{
+                        alert('Amount exceeds wallet balance');
+                        return;
+                    }}
+                    
+                    button.disabled = true;
+                    button.textContent = 'Withdrawing...';
+                    
+                    try {{
+                        const response = await fetch('/admin/withdraw', {{
+                            method: 'POST',
+                            headers: {{
+                                'Content-Type': 'application/json',
+                            }},
+                            credentials: 'same-origin',
+                            body: JSON.stringify({{ amount: amount }})
+                        }});
+                        
+                        if (response.ok) {{
+                            const data = await response.json();
+                            document.getElementById('token-text').textContent = data.token;
+                            tokenResult.style.display = 'block';
+                            closeWithdrawModal();
+                        }} else {{
+                            const errorData = await response.json();
+                            alert('Failed to withdraw balance: ' + (errorData.detail || 'Unknown error'));
+                        }}
+                    }} catch (error) {{
+                        alert('Error: ' + error.message);
+                    }} finally {{
+                        button.disabled = false;
+                        button.textContent = 'Withdraw';
+                    }}
+                }}
+
+                function copyToken() {{
+                    const tokenText = document.getElementById('token-text');
+                    navigator.clipboard.writeText(tokenText.textContent).then(() => {{
+                        const copyBtn = document.getElementById('copy-btn');
+                        const originalText = copyBtn.textContent;
+                        copyBtn.textContent = 'Copied!';
+                        setTimeout(() => {{
+                            copyBtn.textContent = originalText;
+                        }}, 2000);
+                    }}).catch(err => {{
+                        alert('Failed to copy token');
+                    }});
+                }}
+
+                function refreshPage() {{
+                    window.location.reload();
+                }}
+
+                window.onclick = function(event) {{
+                    const modal = document.getElementById('withdraw-modal');
+                    if (event.target == modal) {{
+                        closeWithdrawModal();
+                    }}
+                }}
+            </script>
         </head>
         <body>
             <h1>Admin Dashboard</h1>
@@ -137,6 +327,37 @@ async def dashboard(request: Request) -> str:
             <p>The balance is calculated by subtracting the combined user balance from the total Cashu wallet balance.</p>
             <p>Total Cashu Balance: {current_balance} sats</p>
             <p>User Balance: {total_user_balance} sats</p>
+            
+            <button id="withdraw-btn" onclick="openWithdrawModal()" {"disabled" if current_balance <= 0 else ""}>
+                Withdraw Balance
+            </button>
+            <button class="refresh-btn" onclick="refreshPage()">
+                Refresh Dashboard
+            </button>
+            
+            <div id="withdraw-modal" class="modal">
+                <div class="modal-content">
+                    <span class="close" onclick="closeWithdrawModal()">&times;</span>
+                    <h3>Withdraw Balance</h3>
+                    <p>Enter amount to withdraw (sats):</p>
+                    <input type="number" id="withdraw-amount" min="1" max="{current_balance}" placeholder="Amount in sats" oninput="checkAmount()">
+                    <p>Maximum: {current_balance} sats</p>
+                    <p>Your recommended balance: {owner_balance} sats</p>
+                    <div id="withdraw-warning" class="warning" style="display: none;">
+                        ⚠️ Warning: Withdrawing more than your balance will use user funds!
+                    </div>
+                    <button id="confirm-withdraw-btn" onclick="performWithdraw()">Withdraw</button>
+                    <button onclick="closeWithdrawModal()" style="background-color: #6c757d;">Cancel</button>
+                </div>
+            </div>
+            
+            <div id="token-result">
+                <strong>Withdrawal Token:</strong>
+                <div id="token-text"></div>
+                <button id="copy-btn" class="copy-btn" onclick="copyToken()">Copy Token</button>
+                <p><em>Save this token! It represents your withdrawn balance.</em></p>
+            </div>
+            
             <h2>User's API Keys</h2>
             <table>
                 <tr>
@@ -160,3 +381,25 @@ async def admin(request: Request) -> str:
     if admin_cookie and admin_cookie == os.getenv("ADMIN_PASSWORD"):
         return await dashboard(request)
     return admin_auth()
+
+
+@admin_router.post("/withdraw")
+async def withdraw(
+    request: Request, withdraw_request: WithdrawRequest
+) -> dict[str, str]:
+    admin_cookie = request.cookies.get("admin_password")
+    if not admin_cookie or admin_cookie != os.getenv("ADMIN_PASSWORD"):
+        raise HTTPException(status_code=403, detail="Unauthorized")
+
+    current_balance = await get_balance("sat")
+
+    if withdraw_request.amount <= 0:
+        raise HTTPException(
+            status_code=400, detail="Withdrawal amount must be positive"
+        )
+
+    if withdraw_request.amount > current_balance:
+        raise HTTPException(status_code=400, detail="Insufficient wallet balance")
+
+    token = await send_token(withdraw_request.amount, "sat")
+    return {"token": token}

router/auth.py

@@ -4,18 +4,18 @@ from typing import Optional
 from fastapi import HTTPException
 from sqlmodel import col, update
 
-from .cashu import credit_balance
 from .db import ApiKey, AsyncSession
-from .models import MODELS
+from .logging import get_logger
 from .payment.cost_caculation import (
-    COST_PER_REQUEST,
-    MODEL_BASED_PRICING,
     CostData,
     CostDataError,
     MaxCostData,
     calculate_cost,
 )
 from .payment.helpers import get_max_cost_for_model
+from .wallet import credit_balance
+
+logger = get_logger(__name__)
 
 # TODO: implement prepaid api key (not like it was before)
 # PREPAID_API_KEY = os.environ.get("PREPAID_API_KEY", None)
@@ -33,7 +33,19 @@ async def validate_bearer_key(
     If it's a cashu key, it redeems it and stores its hash and balance.
     Otherwise checks if the hash of the key exists.
     """
+    logger.debug(
+        "Starting bearer key validation",
+        extra={
+            "key_preview": bearer_key[:20] + "..."
+            if len(bearer_key) > 20
+            else bearer_key,
+            "has_refund_address": bool(refund_address),
+            "has_expiry_time": bool(key_expiry_time),
+        },
+    )
+
     if not bearer_key:
+        logger.error("Empty bearer key provided")
         raise HTTPException(
             status_code=401,
             detail={
@@ -46,23 +58,108 @@ async def validate_bearer_key(
         )
 
     if bearer_key.startswith("sk-"):
+        logger.debug(
+            "Processing sk- prefixed API key",
+            extra={"key_preview": bearer_key[:10] + "..."},
+        )
+
         if existing_key := await session.get(ApiKey, bearer_key[3:]):
+            logger.info(
+                "Existing sk- API key found",
+                extra={
+                    "key_hash": existing_key.hashed_key[:8] + "...",
+                    "balance": existing_key.balance,
+                    "total_requests": existing_key.total_requests,
+                },
+            )
+
             if key_expiry_time is not None:
                 existing_key.key_expiry_time = key_expiry_time
+                logger.debug(
+                    "Updated key expiry time",
+                    extra={
+                        "key_hash": existing_key.hashed_key[:8] + "...",
+                        "expiry_time": key_expiry_time,
+                    },
+                )
+
             if refund_address is not None:
                 existing_key.refund_address = refund_address
+                logger.debug(
+                    "Updated refund address",
+                    extra={
+                        "key_hash": existing_key.hashed_key[:8] + "...",
+                        "refund_address_preview": refund_address[:20] + "..."
+                        if len(refund_address) > 20
+                        else refund_address,
+                    },
+                )
+
             return existing_key
+        else:
+            logger.warning(
+                "sk- API key not found in database",
+                extra={"key_preview": bearer_key[:10] + "..."},
+            )
 
     if bearer_key.startswith("cashu"):
+        logger.debug(
+            "Processing Cashu token",
+            extra={
+                "token_preview": bearer_key[:20] + "...",
+                "token_type": bearer_key[:6] if len(bearer_key) >= 6 else bearer_key,
+            },
+        )
+
         try:
             hashed_key = hashlib.sha256(bearer_key.encode()).hexdigest()
+            logger.debug(
+                "Generated token hash", extra={"hash_preview": hashed_key[:16] + "..."}
+            )
+
             if existing_key := await session.get(ApiKey, hashed_key):
+                logger.info(
+                    "Existing Cashu token found",
+                    extra={
+                        "key_hash": existing_key.hashed_key[:8] + "...",
+                        "balance": existing_key.balance,
+                        "total_requests": existing_key.total_requests,
+                    },
+                )
+
                 if key_expiry_time is not None:
                     existing_key.key_expiry_time = key_expiry_time
+                    logger.debug(
+                        "Updated key expiry time for existing Cashu key",
+                        extra={
+                            "key_hash": existing_key.hashed_key[:8] + "...",
+                            "expiry_time": key_expiry_time,
+                        },
+                    )
+
                 if refund_address is not None:
                     existing_key.refund_address = refund_address
+                    logger.debug(
+                        "Updated refund address for existing Cashu key",
+                        extra={
+                            "key_hash": existing_key.hashed_key[:8] + "...",
+                            "refund_address_preview": refund_address[:20] + "..."
+                            if len(refund_address) > 20
+                            else refund_address,
+                        },
+                    )
+
                 return existing_key
 
+            logger.info(
+                "Creating new Cashu token entry",
+                extra={
+                    "hash_preview": hashed_key[:16] + "...",
+                    "has_refund_address": bool(refund_address),
+                    "has_expiry_time": bool(key_expiry_time),
+                },
+            )
+
             new_key = ApiKey(
                 hashed_key=hashed_key,
                 balance=0,
@@ -71,14 +168,44 @@ async def validate_bearer_key(
             )
             session.add(new_key)
             await session.flush()
+
+            logger.debug(
+                "New key created, starting token redemption",
+                extra={"key_hash": hashed_key[:8] + "..."},
+            )
+
             msats = await credit_balance(bearer_key, new_key, session)
             if msats <= 0:
+                logger.error(
+                    "Token redemption returned zero or negative amount",
+                    extra={"msats": msats, "key_hash": hashed_key[:8] + "..."},
+                )
                 raise Exception("Token redemption failed")
+
             await session.refresh(new_key)
             await session.commit()
+
+            logger.info(
+                "New Cashu token successfully redeemed and stored",
+                extra={
+                    "key_hash": hashed_key[:8] + "...",
+                    "redeemed_msats": msats,
+                    "final_balance": new_key.balance,
+                },
+            )
+
             return new_key
         except Exception as e:
-            print(f"Redemption failed: {e}")
+            logger.error(
+                "Cashu token redemption failed",
+                extra={
+                    "error": str(e),
+                    "error_type": type(e).__name__,
+                    "token_preview": bearer_key[:20] + "..."
+                    if len(bearer_key) > 20
+                    else bearer_key,
+                },
+            )
             raise HTTPException(
                 status_code=401,
                 detail={
@@ -89,6 +216,17 @@ async def validate_bearer_key(
                     }
                 },
             )
+
+    logger.error(
+        "Invalid API key format",
+        extra={
+            "key_preview": bearer_key[:10] + "..."
+            if len(bearer_key) > 10
+            else bearer_key,
+            "key_length": len(bearer_key),
+        },
+    )
+
     raise HTTPException(
         status_code=401,
         detail={
@@ -101,17 +239,34 @@ async def validate_bearer_key(
     )
 
 
-async def pay_for_request(
-    key: ApiKey,
-    session: AsyncSession,
-    body: dict,
-) -> None:
-    # Use global COST_PER_REQUEST as default, override if model-based pricing is enabled
-    cost_per_request = COST_PER_REQUEST
-    if MODEL_BASED_PRICING and MODELS:
-        cost_per_request = get_max_cost_for_model(model=body["model"])
+async def pay_for_request(key: ApiKey, session: AsyncSession, body: dict) -> int:
+    """Process payment for a request."""
+    model = body["model"]
+    cost_per_request = get_max_cost_for_model(model=model)
+
+    logger.info(
+        "Processing payment for request",
+        extra={
+            "key_hash": key.hashed_key[:8] + "...",
+            "current_balance": key.balance,
+            "required_cost": cost_per_request,
+            "model": model,
+            "sufficient_balance": key.balance >= cost_per_request,
+        },
+    )
 
     if key.balance < cost_per_request:
+        logger.warning(
+            "Insufficient balance for request",
+            extra={
+                "key_hash": key.hashed_key[:8] + "...",
+                "balance": key.balance,
+                "required": cost_per_request,
+                "shortfall": cost_per_request - key.balance,
+                "model": model,
+            },
+        )
+
         raise HTTPException(
             status_code=402,
             detail={
@@ -123,6 +278,15 @@ async def pay_for_request(
             },
         )
 
+    logger.debug(
+        "Charging base cost for request",
+        extra={
+            "key_hash": key.hashed_key[:8] + "...",
+            "cost": cost_per_request,
+            "balance_before": key.balance,
+        },
+    )
+
     # Charge the base cost for the request atomically to avoid race conditions
     stmt = (
         update(ApiKey)
@@ -136,7 +300,17 @@ async def pay_for_request(
     )
     result = await session.exec(stmt)  # type: ignore[call-overload]
     await session.commit()
+
     if result.rowcount == 0:
+        logger.error(
+            "Concurrent request depleted balance",
+            extra={
+                "key_hash": key.hashed_key[:8] + "...",
+                "required_cost": cost_per_request,
+                "current_balance": key.balance,
+            },
+        )
+
         # Another concurrent request spent the balance first
         raise HTTPException(
             status_code=402,
@@ -148,6 +322,50 @@ async def pay_for_request(
                 }
             },
         )
+
+    await session.refresh(key)
+
+    logger.info(
+        "Payment processed successfully",
+        extra={
+            "key_hash": key.hashed_key[:8] + "...",
+            "charged_amount": cost_per_request,
+            "new_balance": key.balance,
+            "total_spent": key.total_spent,
+            "total_requests": key.total_requests,
+            "model": model,
+        },
+    )
+
+    return cost_per_request
+
+
+async def revert_pay_for_request(
+    key: ApiKey, session: AsyncSession, cost_per_request: int
+) -> None:
+    stmt = (
+        update(ApiKey)
+        .where(col(ApiKey.hashed_key) == key.hashed_key)
+        .values(
+            balance=col(ApiKey.balance) + cost_per_request,
+            total_spent=col(ApiKey.total_spent) - cost_per_request,
+            total_requests=col(ApiKey.total_requests) - 1,
+        )
+    )
+
+    result = await session.exec(stmt)  # type: ignore[call-overload]
+    await session.commit()
+    if result.rowcount == 0:
+        raise HTTPException(
+            status_code=402,
+            detail={
+                "error": {
+                    "message": f"failed to revert request payment: {cost_per_request} mSats required. {key.balance} available.",
+                    "type": "payment_error",
+                    "code": "payment_error",
+                }
+            },
+        )
     await session.refresh(key)
 
 
@@ -159,25 +377,81 @@ async def adjust_payment_for_tokens(
     This is called after the initial payment and the upstream request is complete.
     Returns cost data to be included in the response.
     """
-    max_cost = get_max_cost_for_model(model=response_data["model"])
+    model = response_data.get("model", "unknown")
+    max_cost = get_max_cost_for_model(model=model)
+
+    logger.debug(
+        "Starting payment adjustment for tokens",
+        extra={
+            "key_hash": key.hashed_key[:8] + "...",
+            "model": model,
+            "max_cost": max_cost,
+            "current_balance": key.balance,
+            "has_usage": "usage" in response_data,
+        },
+    )
 
     match calculate_cost(response_data, max_cost):
         case MaxCostData() as cost:
+            logger.debug(
+                "Using max cost data (no token adjustment)",
+                extra={
+                    "key_hash": key.hashed_key[:8] + "...",
+                    "model": model,
+                    "max_cost": cost.total_msats,
+                },
+            )
             return cost.dict()
+
         case CostData() as cost:
             # If token-based pricing is enabled and base cost is 0, use token-based cost
             # Otherwise, token cost is additional to the base cost
             cost_difference = cost.total_msats - max_cost
 
+            logger.info(
+                "Calculated token-based cost",
+                extra={
+                    "key_hash": key.hashed_key[:8] + "...",
+                    "model": model,
+                    "token_cost": cost.total_msats,
+                    "max_cost": max_cost,
+                    "cost_difference": cost_difference,
+                    "input_msats": cost.input_msats,
+                    "output_msats": cost.output_msats,
+                },
+            )
+
             if cost_difference == 0:
+                logger.debug(
+                    "No cost adjustment needed",
+                    extra={"key_hash": key.hashed_key[:8] + "...", "model": model},
+                )
                 await session.commit()
                 return cost.dict()
 
             if cost_difference > 0:
                 # Need to charge more
+                logger.info(
+                    "Additional charge required for token usage",
+                    extra={
+                        "key_hash": key.hashed_key[:8] + "...",
+                        "additional_charge": cost_difference,
+                        "current_balance": key.balance,
+                        "sufficient_balance": key.balance >= cost_difference,
+                        "model": model,
+                    },
+                )
+
                 if key.balance < cost_difference:
-                    print(
-                        f"Warning: Insufficient balance for token-based pricing adjustment: {key.hashed_key[:10]}..."
+                    logger.warning(
+                        "Insufficient balance for token-based pricing adjustment",
+                        extra={
+                            "key_hash": key.hashed_key[:8] + "...",
+                            "required": cost_difference,
+                            "available": key.balance,
+                            "shortfall": cost_difference - key.balance,
+                            "model": model,
+                        },
                     )
                     await session.commit()
                 else:
@@ -192,12 +466,43 @@ async def adjust_payment_for_tokens(
                     )
                     result = await session.exec(charge_stmt)  # type: ignore[call-overload]
                     await session.commit()
+
                     if result.rowcount:
                         cost.total_msats = max_cost + cost_difference
                         await session.refresh(key)
+
+                        logger.info(
+                            "Additional charge applied successfully",
+                            extra={
+                                "key_hash": key.hashed_key[:8] + "...",
+                                "charged_amount": cost_difference,
+                                "new_balance": key.balance,
+                                "total_cost": cost.total_msats,
+                                "model": model,
+                            },
+                        )
+                    else:
+                        logger.warning(
+                            "Failed to apply additional charge (concurrent operation)",
+                            extra={
+                                "key_hash": key.hashed_key[:8] + "...",
+                                "attempted_charge": cost_difference,
+                                "model": model,
+                            },
+                        )
             else:
                 # Refund some of the base cost
                 refund = abs(cost_difference)
+                logger.info(
+                    "Refunding excess payment",
+                    extra={
+                        "key_hash": key.hashed_key[:8] + "...",
+                        "refund_amount": refund,
+                        "current_balance": key.balance,
+                        "model": model,
+                    },
+                )
+
                 refund_stmt = (
                     update(ApiKey)
                     .where(col(ApiKey.hashed_key) == key.hashed_key)
@@ -211,8 +516,30 @@ async def adjust_payment_for_tokens(
                 cost.total_msats = max_cost - refund
                 await session.refresh(key)
 
+                logger.info(
+                    "Refund processed successfully",
+                    extra={
+                        "key_hash": key.hashed_key[:8] + "...",
+                        "refunded_amount": refund,
+                        "new_balance": key.balance,
+                        "final_cost": cost.total_msats,
+                        "model": model,
+                    },
+                )
+
             return cost.dict()
+
         case CostDataError() as error:
+            logger.error(
+                "Cost calculation error during payment adjustment",
+                extra={
+                    "key_hash": key.hashed_key[:8] + "...",
+                    "model": model,
+                    "error_message": error.message,
+                    "error_code": error.code,
+                },
+            )
+
             raise HTTPException(
                 status_code=400,
                 detail={

router/cashu.py

@@ -1,206 +0,0 @@
-import asyncio
-import os
-import time
-from typing import cast
-
-from sixty_nuts import Wallet
-from sixty_nuts.mint import CurrencyUnit
-from sqlmodel import col, func, select, update
-
-from .db import ApiKey, AsyncSession, get_session
-
-RECEIVE_LN_ADDRESS = os.environ["RECEIVE_LN_ADDRESS"]
-MINT = os.environ.get("MINT", "https://mint.minibits.cash/Bitcoin")
-MINIMUM_PAYOUT = int(os.environ.get("MINIMUM_PAYOUT", 100))
-REFUND_PROCESSING_INTERVAL = int(os.environ.get("REFUND_PROCESSING_INTERVAL", 3600))
-PAYOUT_INTERVAL = int(os.environ.get("PAYOUT_INTERVAL", 300))  # Default 5 minutes
-DEV_LN_ADDRESS = "routstr@minibits.cash"
-DEVS_DONATION_RATE = float(os.environ.get("DEVS_DONATION_RATE", 0.021))  # 2.1%
-NSEC = os.environ["NSEC"]  # Nostr private key for the wallet
-CURRENCY = cast(CurrencyUnit, os.environ.get("CURRENCY", "sat"))
-
-wallet_instance: Wallet | None = None
-
-
-async def init_wallet() -> None:
-    global wallet_instance
-    wallet_instance = await Wallet.create(nsec=NSEC)
-
-
-def wallet() -> Wallet:
-    global wallet_instance
-    if wallet_instance is None:
-        raise ValueError("Wallet not initialized")
-    return wallet_instance
-
-
-async def delete_key_if_zero_balance(key: ApiKey, session: AsyncSession) -> None:
-    """Delete the given API key if its balance is zero."""
-    if key.balance == 0:
-        await session.delete(key)
-        await session.commit()
-
-
-async def pay_out() -> None:
-    """
-    Calculates the pay-out amount based on the spent balance, profit, and donation rate.
-    """
-    try:
-        from .db import create_session
-
-        async with create_session() as session:
-            result = await session.exec(
-                select(func.sum(col(ApiKey.balance))).where(ApiKey.balance > 0)
-            )
-            balance = result.one_or_none()
-            if not balance:
-                # No balance to pay out - this is OK, not an error
-                return
-
-            user_balance_sats = balance // 1000
-            wallet_balance_sats = await wallet().get_balance()
-
-            # Handle edge cases more gracefully
-            if wallet_balance_sats < user_balance_sats:
-                print(
-                    f"Warning: Wallet balance ({wallet_balance_sats} sats) is less than user balance ({user_balance_sats} sats). Skipping payout."
-                )
-                return
-
-            if (revenue := wallet_balance_sats - user_balance_sats) <= MINIMUM_PAYOUT:
-                # Not enough revenue yet - this is OK
-                return
-
-            devs_donation = int(revenue * DEVS_DONATION_RATE)
-            owners_draw = revenue - devs_donation
-
-            # Send payouts
-            await wallet().send_to_lnurl(RECEIVE_LN_ADDRESS, owners_draw)
-            await wallet().send_to_lnurl(DEV_LN_ADDRESS, devs_donation)
-
-    except Exception as e:
-        print(f"Error in pay_out: {e}")
-
-
-# Periodic payout task
-async def periodic_payout() -> None:
-    while True:
-        try:
-            await asyncio.sleep(300)  # Run every 5 minutes
-            await pay_out()
-        except asyncio.CancelledError:
-            break
-        except Exception as e:
-            print(f"Error in periodic payout: {e}")
-            # Continue running even if payout fails
-
-
-async def credit_balance(cashu_token: str, key: ApiKey, session: AsyncSession) -> int:
-    """Redeem a Cashu token and credit the amount to the API key balance."""
-    try:
-        amount_sats, _ = await wallet().redeem(cashu_token)
-    except Exception as e:
-        print(f"Error in credit_balance: {e}")
-        # Ensure the balance cannot become negative if redeem fails
-        return 0
-
-    if amount_sats <= 0:
-        return 0
-
-    amount_msats = amount_sats * 1000
-
-    # Apply the balance change atomically to avoid race conditions when topping
-    # up the same key concurrently.
-    stmt = (
-        update(ApiKey)
-        .where(col(ApiKey.hashed_key) == key.hashed_key)
-        .values(balance=col(ApiKey.balance) + amount_msats)
-    )
-    await session.exec(stmt)  # type: ignore[call-overload]
-    await session.commit()
-    await session.refresh(key)
-
-    return amount_msats
-
-
-async def check_for_refunds() -> None:
-    """
-    Periodically checks for API keys that are eligible for refunds and processes them.
-
-    Raises:
-        Exception: If an error occurs during the refund check process.
-    """
-    # Setting REFUND_PROCESSING_INTERVAL to 0 disables it
-    if REFUND_PROCESSING_INTERVAL == 0:
-        print("Automatic refund processing is disabled.")
-        return
-
-    while True:
-        try:
-            async for session in get_session():
-                result = await session.exec(select(ApiKey))
-                keys = result.all()
-                current_time = int(time.time())
-                for key in keys:
-                    if (
-                        key.balance > 0
-                        and key.refund_address
-                        and key.key_expiry_time
-                        and key.key_expiry_time < current_time
-                    ):
-                        print(
-                            f"       DEBUG   Refunding key {key.hashed_key[:3] + '[...]' + key.hashed_key[-3:]}, Current Time: {current_time}, Expirary Time: {key.key_expiry_time}",
-                            flush=True,
-                        )
-                        await refund_balance(key.balance, key, session)
-                        await delete_key_if_zero_balance(key, session)
-
-            # Sleep for the specified interval before checking again
-            await asyncio.sleep(REFUND_PROCESSING_INTERVAL)
-        except asyncio.CancelledError:
-            break
-        except Exception as e:
-            print(f"Error during refund check: {e}")
-
-
-async def refund_balance(amount_msats: int, key: ApiKey, session: AsyncSession) -> int:
-    if amount_msats <= 0:
-        amount_msats = key.balance
-
-    # Convert msats to sats for cashu wallet
-    amount_sats = amount_msats // 1000
-    if amount_sats == 0:
-        raise ValueError("Amount too small to refund (less than 1 sat)")
-
-    # Atomically deduct the balance to avoid race conditions when multiple
-    # refunds are triggered concurrently.
-    stmt = (
-        update(ApiKey)
-        .where(col(ApiKey.hashed_key) == key.hashed_key)
-        .where(col(ApiKey.balance) >= amount_msats)
-        .values(balance=col(ApiKey.balance) - amount_msats)
-    )
-    result = await session.exec(stmt)  # type: ignore[call-overload]
-    await session.commit()
-    if result.rowcount == 0:
-        raise ValueError("Insufficient balance.")
-    await session.refresh(key)
-    await delete_key_if_zero_balance(key, session)
-
-    if key.refund_address is None:
-        raise ValueError("Refund address not set.")
-
-    return await wallet().send_to_lnurl(key.refund_address, amount=amount_sats)
-
-
-async def x_cashu_refund(key: ApiKey, session: AsyncSession) -> str:
-    refund_token = await wallet().send(key.balance)
-    await session.delete(key)
-    await session.commit()
-    return refund_token
-
-
-async def redeem(cashu_token: str, lnurl: str) -> int:
-    amount_sats, _ = await wallet().redeem(cashu_token)
-    await wallet().send_to_lnurl(lnurl, amount=amount_sats)
-    return amount_sats

router/logging.py

@@ -0,0 +1,269 @@
+import logging.config
+import logging.handlers
+import os
+import re
+import tomllib
+from datetime import datetime
+from pathlib import Path
+from typing import Any
+
+from pythonjsonlogger import jsonlogger
+
+
+class DailyRotatingFileHandler(logging.handlers.TimedRotatingFileHandler):
+    """Custom TimedRotatingFileHandler that creates date-based filenames."""
+
+    def __init__(self, filename: str, **kwargs: Any) -> None:
+        """Initialize with a base filename pattern."""
+        self.base_dir = os.path.dirname(filename)
+        self.base_name = os.path.basename(filename).replace(".log", "")
+
+        today = datetime.now().strftime("%Y-%m-%d")
+        self.current_date = today
+        dated_filename = os.path.join(self.base_dir, f"{self.base_name}_{today}.log")
+
+        super().__init__(dated_filename, **kwargs)
+
+    def doRollover(self) -> None:
+        """Override rollover to create new date-based filename."""
+        if self.stream:
+            self.stream.close()
+
+        new_date = datetime.now().strftime("%Y-%m-%d")
+        new_filename = os.path.join(self.base_dir, f"{self.base_name}_{new_date}.log")
+
+        self.baseFilename = new_filename
+        self.current_date = new_date
+
+        # FIX ME: not sure if we need this
+        # self._cleanup_old_files()
+
+        if not self.delay:
+            self.stream = self._open()
+
+    def _cleanup_old_files(self) -> None:
+        """Remove old log files beyond backupCount."""
+        if self.backupCount > 0:
+            log_files = []
+            if os.path.exists(self.base_dir):
+                for file in os.listdir(self.base_dir):
+                    if file.startswith(f"{self.base_name}_") and file.endswith(".log"):
+                        file_path = os.path.join(self.base_dir, file)
+                        log_files.append((file_path, os.path.getmtime(file_path)))
+
+            log_files.sort(key=lambda x: x[1], reverse=True)
+
+            for file_path, _ in log_files[self.backupCount :]:
+                try:
+                    os.remove(file_path)
+                except OSError:
+                    pass
+
+
+def get_package_version() -> str:
+    """Read the package version from pyproject.toml."""
+    try:
+        # Find project root by looking for pyproject.toml
+        current_path = Path(__file__).parent
+        while current_path != current_path.parent:
+            pyproject_path = current_path / "pyproject.toml"
+            if pyproject_path.exists():
+                with open(pyproject_path, "rb") as f:
+                    pyproject_data = tomllib.load(f)
+                version = pyproject_data.get("project", {}).get("version", "unknown")
+                return version
+            current_path = current_path.parent
+
+        # Fallback: try the simple path resolution (3 levels up for router/logging/logging_config.py)
+        pyproject_path = Path(__file__).parent.parent.parent / "pyproject.toml"
+        if pyproject_path.exists():
+            with open(pyproject_path, "rb") as f:
+                pyproject_data = tomllib.load(f)
+            version = pyproject_data.get("project", {}).get("version", "unknown")
+            return version
+
+        return "unknown"
+    except Exception:
+        return "unknown"
+
+
+class VersionFilter(logging.Filter):
+    """Filter to add package version to all log records."""
+
+    def __init__(self) -> None:
+        super().__init__()
+        self.version = get_package_version()
+
+    def filter(self, record: logging.LogRecord) -> bool:
+        """Add version information to the log record."""
+        record.version = self.version
+        return True
+
+
+class SecurityFilter(logging.Filter):
+    """Filter to remove sensitive information from logs."""
+
+    SENSITIVE_KEYS = {
+        "authorization",
+        "x-cashu",
+        "bearer",
+        "token",
+        "key",
+        "secret",
+        "password",
+        "cashu_token",
+        "bearer_key",
+        "api_key",
+        "nsec",
+        "upstream_api_key",
+        "refund_address",
+    }
+
+    def filter(self, record: logging.LogRecord) -> bool:
+        """Filter out sensitive information from log records."""
+        try:
+            message = record.getMessage()
+
+            for key in self.SENSITIVE_KEYS:
+                if key in message.lower():
+                    patterns = [
+                        rf"{key}[:\s=]+([a-zA-Z0-9_\-\.]+)",  # key: value or key=value
+                        rf'{key}[:\s=]+["\']([^"\']+)["\']',  # key: "value" or key='value'
+                        r"Bearer\s+([a-zA-Z0-9_\-\.]+)",  # Bearer token
+                        r"cashu[A-Z]+([a-zA-Z0-9_\-\.=/+]+)",  # Cashu tokens
+                    ]
+
+                    for pattern in patterns:
+                        message = re.sub(
+                            pattern, f"{key}: [REDACTED]", message, flags=re.IGNORECASE
+                        )
+
+            record.msg = message
+            record.args = ()
+
+        except Exception:
+            pass
+
+        return True
+
+
+def get_log_level() -> str:
+    """Get log level from environment variable."""
+    return os.environ.get("LOG_LEVEL", "INFO").upper()
+
+
+def should_enable_console_logging() -> bool:
+    """Check if console logging should be enabled."""
+    return os.environ.get("ENABLE_CONSOLE_LOGGING", "true").lower() in (
+        "true",
+        "1",
+        "yes",
+    )
+
+
+def setup_logging() -> None:
+    """Configure centralized logging for the application."""
+
+    log_level = get_log_level()
+    console_enabled = should_enable_console_logging()
+
+    # Determine which handlers to use
+    handlers = ["file"]
+    if console_enabled:
+        handlers.append("console")
+
+    LOGGING_CONFIG = {
+        "version": 1,
+        "disable_existing_loggers": False,
+        "formatters": {
+            "json": {
+                "()": jsonlogger.JsonFormatter,
+                "format": "%(asctime)s %(name)s %(levelname)s %(message)s %(pathname)s %(lineno)d %(version)s",
+                "datefmt": "%Y-%m-%d %H:%M:%S",
+            },
+            "standard": {
+                "format": "%(asctime)s [%(levelname)s] %(name)s v%(version)s: %(message)s",
+                "datefmt": "%Y-%m-%d %H:%M:%S",
+            },
+        },
+        "filters": {
+            "version_filter": {"()": VersionFilter},
+            "security_filter": {"()": SecurityFilter},
+        },
+        "handlers": {
+            "console": {
+                "class": "logging.StreamHandler",
+                "level": log_level,
+                "formatter": "standard",
+                "stream": "ext://sys.stdout",
+                "filters": ["version_filter", "security_filter"],
+            },
+            "file": {
+                "()": DailyRotatingFileHandler,
+                "level": log_level,
+                "formatter": "json",
+                "filename": "logs/app.log",
+                "when": "midnight",  # Rotate at midnight each day
+                "interval": 1,  # Every 1 day
+                "backupCount": 30,  # Keep 30 days of logs
+                "atTime": None,  # Rotate at midnight (00:00)
+                "filters": ["version_filter", "security_filter"],
+            },
+        },
+        "loggers": {
+            "router": {
+                "level": log_level,
+                "handlers": handlers,
+                "propagate": False,
+            },
+            "router.payment": {
+                "level": log_level,
+                "handlers": handlers,
+                "propagate": False,
+            },
+            "router.cashu": {
+                "level": log_level,
+                "handlers": handlers,
+                "propagate": False,
+            },
+            "router.proxy": {
+                "level": log_level,
+                "handlers": handlers,
+                "propagate": False,
+            },
+            "router.auth": {
+                "level": log_level,
+                "handlers": handlers,
+                "propagate": False,
+            },
+            # Suppress verbose third-party logging
+            "httpx": {
+                "level": "WARNING",
+                "handlers": ["console"] if console_enabled else [],
+                "propagate": False,
+            },
+            "httpcore": {
+                "level": "WARNING",
+                "handlers": ["console"] if console_enabled else [],
+                "propagate": False,
+            },
+            "uvicorn.access": {
+                "level": "WARNING",
+                "handlers": ["console"] if console_enabled else [],
+                "propagate": False,
+            },
+        },
+        "root": {
+            "level": log_level,
+            "handlers": ["console"] if console_enabled else [],
+        },
+    }
+
+    os.makedirs("logs", exist_ok=True)
+
+    logging.config.dictConfig(LOGGING_CONFIG)
+
+
+def get_logger(name: str) -> logging.Logger:
+    """Get a logger instance for the given module name."""
+    return logging.getLogger(name)

router/main.py

@@ -8,33 +8,64 @@ from fastapi.middleware.cors import CORSMiddleware
 
 from .account import wallet_router
 from .admin import admin_router
-from .cashu import check_for_refunds, init_wallet, periodic_payout
 from .db import init_db
 from .discovery import providers_router
+from .logging import get_logger, setup_logging
 from .models import MODELS, models_router, update_sats_pricing
 from .proxy import proxy_router
+from .wallet import check_for_refunds, periodic_payout
+
+# Initialize logging first
+setup_logging()
+logger = get_logger(__name__)
 
 __version__ = "0.0.1"
 
 
 @asynccontextmanager
 async def lifespan(_: FastAPI) -> AsyncGenerator[None, None]:
-    await init_db()
-    await init_wallet()
-
-    pricing_task = asyncio.create_task(update_sats_pricing())
-    refund_task = asyncio.create_task(check_for_refunds())
-    payout_task = asyncio.create_task(periodic_payout())
+    logger.info("Application startup initiated", extra={"version": __version__})
 
     try:
+        await init_db()
+        logger.info("Database initialized successfully")
+
+        logger.info("Wallet initialized successfully")
+
+        pricing_task = asyncio.create_task(update_sats_pricing())
+        refund_task = asyncio.create_task(check_for_refunds())
+        payout_task = asyncio.create_task(periodic_payout())
+
+        logger.info(
+            "Background tasks started successfully",
+            extra={"tasks": ["pricing", "refunds", "payouts"]},
+        )
+
         yield
+
+    except Exception as e:
+        logger.error(
+            "Application startup failed",
+            extra={"error": str(e), "error_type": type(e).__name__},
+        )
+        raise
     finally:
+        logger.info("Application shutdown initiated")
+
         refund_task.cancel()
         pricing_task.cancel()
         payout_task.cancel()
-        await asyncio.gather(
-            pricing_task, refund_task, payout_task, return_exceptions=True
-        )
+
+        try:
+            await asyncio.gather(
+                pricing_task, refund_task, payout_task, return_exceptions=True
+            )
+            logger.info("Background tasks stopped successfully")
+        except Exception as e:
+            logger.error(
+                "Error stopping background tasks",
+                extra={"error": str(e), "error_type": type(e).__name__},
+            )
 
 
 app = FastAPI(
@@ -54,9 +85,15 @@ app.add_middleware(
     allow_headers=["*"],
 )
 
+logger.info(
+    "CORS middleware configured",
+    extra={"allowed_origins": os.environ.get("CORS_ORIGINS", "*").split(",")},
+)
+
 
 @app.get("/")
 async def info() -> dict:
+    logger.info("Info endpoint accessed")
     return {
         "name": app.title,
         "description": app.description,
@@ -74,3 +111,8 @@ app.include_router(admin_router)
 app.include_router(wallet_router)
 app.include_router(providers_router)
 app.include_router(proxy_router)
+
+logger.info(
+    "Application initialized successfully",
+    extra={"version": __version__, "routers_count": 5},
+)

router/models.py

@@ -144,6 +144,7 @@ async def update_sats_pricing() -> None:
             break
 
 
+@models_router.get("/models")
 @models_router.get("/v1/models")
 async def models() -> dict:
     return {"data": MODELS}

router/payment/cost_caculation.py

@@ -2,7 +2,10 @@ import os
 
 from pydantic import BaseModel
 
-from router.models import MODELS
+from ..logging import get_logger
+from ..models import MODELS
+
+logger = get_logger(__name__)
 
 COST_PER_REQUEST = (
     int(os.environ.get("COST_PER_REQUEST", "1")) * 1000
@@ -15,6 +18,16 @@ COST_PER_1K_OUTPUT_TOKENS = (
 )  # Convert to msats
 MODEL_BASED_PRICING = os.environ.get("MODEL_BASED_PRICING", "false").lower() == "true"
 
+logger.info(
+    "Cost calculation initialized",
+    extra={
+        "cost_per_request_msats": COST_PER_REQUEST,
+        "cost_per_1k_input_tokens_msats": COST_PER_1K_INPUT_TOKENS,
+        "cost_per_1k_output_tokens_msats": COST_PER_1K_OUTPUT_TOKENS,
+        "model_based_pricing": MODEL_BASED_PRICING,
+    },
+)
+
 
 class CostData(BaseModel):
     base_msats: int
@@ -35,6 +48,25 @@ class CostDataError(BaseModel):
 def calculate_cost(
     response_data: dict, max_cost: int
 ) -> CostData | MaxCostData | CostDataError:
+    """
+    Calculate the cost of an API request based on token usage.
+
+    Args:
+        response_data: Response data containing usage information
+        max_cost: Maximum cost in millisats
+
+    Returns:
+        Cost data or error information
+    """
+    logger.debug(
+        "Starting cost calculation",
+        extra={
+            "max_cost_msats": max_cost,
+            "has_usage_data": "usage" in response_data,
+            "response_model": response_data.get("model", "unknown"),
+        },
+    )
+
     cost_data = MaxCostData(
         base_msats=max_cost,
         input_msats=0,
@@ -43,7 +75,13 @@ def calculate_cost(
     )
 
     if "usage" not in response_data or response_data["usage"] is None:
-        print("No usage data in response, using base cost only")
+        logger.warning(
+            "No usage data in response, using base cost only",
+            extra={
+                "max_cost_msats": max_cost,
+                "model": response_data.get("model", "unknown"),
+            },
+        )
         return cost_data
 
     MSATS_PER_1K_INPUT_TOKENS = COST_PER_1K_INPUT_TOKENS
@@ -51,7 +89,22 @@ def calculate_cost(
 
     if MODEL_BASED_PRICING and MODELS:
         response_model = response_data.get("model", "")
+        logger.debug(
+            "Using model-based pricing",
+            extra={
+                "model": response_model,
+                "available_models": [model.id for model in MODELS],
+            },
+        )
+
         if response_model not in [model.id for model in MODELS]:
+            logger.error(
+                "Invalid model in response",
+                extra={
+                    "response_model": response_model,
+                    "available_models": [model.id for model in MODELS],
+                },
+            )
             return CostDataError(
                 message=f"Invalid model in response: {response_model}",
                 code="model_not_found",
@@ -59,6 +112,10 @@ def calculate_cost(
 
         model = next(model for model in MODELS if model.id == response_model)
         if model.sats_pricing is None:
+            logger.error(
+                "Model pricing not defined",
+                extra={"model": response_model, "model_id": model.id},
+            )
             return CostDataError(
                 message="Model pricing not defined", code="pricing_not_found"
             )
@@ -66,8 +123,23 @@ def calculate_cost(
         MSATS_PER_1K_INPUT_TOKENS = model.sats_pricing.prompt * 1_000_000  # type: ignore
         MSATS_PER_1K_OUTPUT_TOKENS = model.sats_pricing.completion * 1_000_000  # type: ignore
 
+        logger.info(
+            "Applied model-specific pricing",
+            extra={
+                "model": response_model,
+                "input_price_msats_per_1k": MSATS_PER_1K_INPUT_TOKENS,
+                "output_price_msats_per_1k": MSATS_PER_1K_OUTPUT_TOKENS,
+            },
+        )
+
     if not (MSATS_PER_1K_OUTPUT_TOKENS and MSATS_PER_1K_INPUT_TOKENS):
-        # If no token pricing is configured, just return base cost
+        logger.warning(
+            "No token pricing configured, using base cost",
+            extra={
+                "base_cost_msats": max_cost,
+                "model": response_data.get("model", "unknown"),
+            },
+        )
         return cost_data
 
     input_tokens = response_data.get("usage", {}).get("prompt_tokens", 0)
@@ -77,6 +149,18 @@ def calculate_cost(
     output_msats = int(round(output_tokens / 1000 * MSATS_PER_1K_OUTPUT_TOKENS, 0))
     token_based_cost = int(round(input_msats + output_msats, 0))
 
+    logger.info(
+        "Calculated token-based cost",
+        extra={
+            "input_tokens": input_tokens,
+            "output_tokens": output_tokens,
+            "input_cost_msats": input_msats,
+            "output_cost_msats": output_msats,
+            "total_cost_msats": token_based_cost,
+            "model": response_data.get("model", "unknown"),
+        },
+    )
+
     return CostData(
         base_msats=0,
         input_msats=input_msats,

router/payment/helpers.py

@@ -6,76 +6,324 @@ from typing import Literal
 import cbor2
 from fastapi import HTTPException, Response
 
-from router.models import MODELS
-from router.payment.cost_caculation import COST_PER_REQUEST
+from ..logging import get_logger
+from ..models import MODELS
+from .cost_caculation import COST_PER_REQUEST, MODEL_BASED_PRICING
+
+logger = get_logger(__name__)
 
 UPSTREAM_BASE_URL = os.environ["UPSTREAM_BASE_URL"]
 UPSTREAM_API_KEY = os.environ.get("UPSTREAM_API_KEY", "")
 
+logger.info(
+    "Payment helpers initialized",
+    extra={
+        "upstream_base_url": UPSTREAM_BASE_URL,
+        "has_upstream_api_key": bool(UPSTREAM_API_KEY),
+        "model_based_pricing": MODEL_BASED_PRICING,
+    },
+)
+
+
+def get_cost_per_request(model: str | None = None) -> int:
+    """Get the cost per request for a given model."""
+    logger.debug(
+        "Calculating cost per request",
+        extra={
+            "model": model,
+            "model_based_pricing": MODEL_BASED_PRICING,
+            "has_models": bool(MODELS),
+        },
+    )
+
+    if MODEL_BASED_PRICING and MODELS and model:
+        cost = get_max_cost_for_model(model=model)
+        logger.debug(
+            "Using model-based cost", extra={"model": model, "cost_msats": cost}
+        )
+        return cost
+
+    logger.debug(
+        "Using default cost per request", extra={"cost_msats": COST_PER_REQUEST}
+    )
+    return COST_PER_REQUEST
+
+
+def check_token_balance(headers: dict, body: dict) -> Literal["sat", "msat"]:
+    """Check if the provided token has sufficient balance."""
+    logger.debug(
+        "Checking token balance",
+        extra={
+            "has_x_cashu": "x-cashu" in headers,
+            "has_authorization": "authorization" in headers,
+            "model": body.get("model", "unknown"),
+        },
+    )
 
-def check_token_balance(
-    headers: dict, body: dict, unit: Literal["sat", "msat"]
-) -> None:
     if x_cashu := headers.get("x-cashu", None):
         cashu_token = x_cashu
+        logger.debug(
+            "Using X-Cashu token",
+            extra={
+                "token_preview": cashu_token[:20] + "..."
+                if len(cashu_token) > 20
+                else cashu_token
+            },
+        )
     elif auth := headers.get("authorization", None):
-        cashu_token = auth.split(" ")[1]
+        cashu_token = auth.split(" ")[1] if len(auth.split(" ")) > 1 else ""
+        logger.debug(
+            "Using Authorization header token",
+            extra={
+                "token_preview": cashu_token[:20] + "..."
+                if len(cashu_token) > 20
+                else cashu_token
+            },
+        )
     else:
+        logger.error("No authentication token provided")
         raise HTTPException(status_code=401, detail="Unauthorized")
-    COST_PER_REQUEST = get_max_cost_for_model(model=body["model"])
+
+    # Handle empty token
+    if not cashu_token:
+        logger.error("Empty token provided")
+        raise HTTPException(
+            status_code=401,
+            detail={
+                "error": {
+                    "message": "API key or Cashu token required",
+                    "type": "invalid_request_error",
+                    "code": "missing_api_key",
+                }
+            },
+        )
+
+    # Handle regular API keys (sk-*)
+    if cashu_token.startswith("sk-"):
+        logger.debug(
+            "Regular API key detected", extra={"key_preview": cashu_token[:10] + "..."}
+        )
+        return "sat"
+
+    cost = get_cost_per_request(model=body.get("model", None))
+
     if cashu_token.startswith("cashuA"):
-        _token = base64_token_json(cashu_token)
-        amount = sum(p["amount"] for t in _token["token"] for p in t["proofs"])
-        unit = _token["unit"]
-        if unit == "msat":
-            pass
-        elif unit == "sat":
-            amount *= 1000
-        if amount < COST_PER_REQUEST:
-            raise HTTPException(status_code=413, detail="Insufficient balance")
+        logger.debug("Processing CashuA token", extra={"required_cost_msats": cost})
+
+        try:
+            _token = base64_token_json(cashu_token)
+            amount = sum(p["amount"] for t in _token["token"] for p in t["proofs"])
+            unit: Literal["sat", "msat"] = _token["unit"]
+
+            if unit == "sat":
+                amount *= 1000
+
+            logger.info(
+                "CashuA token parsed successfully",
+                extra={
+                    "amount": amount,
+                    "unit": _token["unit"],
+                    "amount_msats": amount,
+                    "required_cost_msats": cost,
+                    "sufficient_balance": amount >= cost,
+                },
+            )
+
+            if amount < cost:
+                logger.warning(
+                    "Insufficient token balance",
+                    extra={
+                        "amount_msats": amount,
+                        "required_msats": cost,
+                        "shortfall_msats": cost - amount,
+                        "unit": unit,
+                    },
+                )
+                raise HTTPException(status_code=413, detail="Insufficient balance")
+
+        except Exception as e:
+            logger.error(
+                "Failed to parse CashuA token",
+                extra={
+                    "error": str(e),
+                    "error_type": type(e).__name__,
+                    "token_preview": cashu_token[:20] + "...",
+                },
+            )
+            raise HTTPException(status_code=401, detail="Invalid token format")
+
     elif cashu_token.startswith("cashuB"):
-        _token = base64_token_cbor(cashu_token)
-        amount = sum(p["a"] for t in _token["t"] for p in t["p"])
-        unit = _token["u"]
-        if unit == "sat":
-            amount *= 1000
-        if amount < COST_PER_REQUEST:
-            raise HTTPException(status_code=413, detail="Insufficient balance")
+        logger.debug("Processing CashuB token", extra={"required_cost_msats": cost})
+
+        try:
+            _token = base64_token_cbor(cashu_token)
+            amount = sum(p["a"] for t in _token["t"] for p in t["p"])
+            unit = _token["u"]
+
+            if unit == "sat":
+                amount *= 1000
+
+            logger.info(
+                "CashuB token parsed successfully",
+                extra={
+                    "amount": amount,
+                    "unit": unit,
+                    "amount_msats": amount,
+                    "required_cost_msats": cost,
+                    "sufficient_balance": amount >= cost,
+                },
+            )
+
+            if amount < cost:
+                logger.warning(
+                    "Insufficient token balance",
+                    extra={
+                        "amount_msats": amount,
+                        "required_msats": cost,
+                        "shortfall_msats": cost - amount,
+                        "unit": unit,
+                    },
+                )
+                raise HTTPException(status_code=413, detail="Insufficient balance")
+
+        except Exception as e:
+            logger.error(
+                "Failed to parse CashuB token",
+                extra={
+                    "error": str(e),
+                    "error_type": type(e).__name__,
+                    "token_preview": cashu_token[:20] + "...",
+                },
+            )
+            raise HTTPException(status_code=401, detail="Invalid token format")
+
     else:
+        logger.error(
+            "Unknown token format",
+            extra={"token_prefix": cashu_token[:10] if cashu_token else "empty"},
+        )
         raise HTTPException(status_code=401, detail="Unauthorized")
 
+    return unit
+
 
 def base64_token_json(cashu_token: str) -> dict:
-    # Version 3 - JSON format
-    encoded = cashu_token[6:]  # Remove "cashuA"
-    # Add correct padding – (-len) % 4 equals 0,1,2,3
-    encoded += "=" * ((-len(encoded)) % 4)
+    """Decode a CashuA (JSON) token."""
+    logger.debug("Decoding CashuA token", extra={"token_length": len(cashu_token)})
 
-    decoded = base64.urlsafe_b64decode(encoded).decode()
-    token_data = json.loads(decoded)
+    try:
+        # Version 3 - JSON format
+        encoded = cashu_token[6:]  # Remove "cashuA"
+        # Add correct padding – (-len) % 4 equals 0,1,2,3
+        encoded += "=" * ((-len(encoded)) % 4)
 
-    return token_data
+        decoded = base64.urlsafe_b64decode(encoded).decode()
+        token_data = json.loads(decoded)
+
+        logger.debug(
+            "CashuA token decoded successfully",
+            extra={
+                "token_proofs_count": sum(
+                    len(t.get("proofs", [])) for t in token_data.get("token", [])
+                ),
+                "unit": token_data.get("unit", "unknown"),
+            },
+        )
+
+        return token_data
+    except Exception as e:
+        logger.error(
+            "Failed to decode CashuA token",
+            extra={"error": str(e), "error_type": type(e).__name__},
+        )
+        raise
 
 
 def base64_token_cbor(cashu_token: str) -> dict:
-    encoded = cashu_token[6:]  # Remove "cashuB"
-    encoded += "=" * ((-len(encoded)) % 4)
-    decoded_bytes = base64.urlsafe_b64decode(encoded)
-    token_data = cbor2.loads(decoded_bytes)
-    return token_data
+    """Decode a CashuB (CBOR) token."""
+    logger.debug("Decoding CashuB token", extra={"token_length": len(cashu_token)})
+
+    try:
+        encoded = cashu_token[6:]  # Remove "cashuB"
+        encoded += "=" * ((-len(encoded)) % 4)
+        decoded_bytes = base64.urlsafe_b64decode(encoded)
+        token_data = cbor2.loads(decoded_bytes)
+
+        logger.debug(
+            "CashuB token decoded successfully",
+            extra={
+                "token_proofs_count": sum(
+                    len(t.get("p", [])) for t in token_data.get("t", [])
+                ),
+                "unit": token_data.get("u", "unknown"),
+            },
+        )
+
+        return token_data
+    except Exception as e:
+        logger.error(
+            "Failed to decode CashuB token",
+            extra={"error": str(e), "error_type": type(e).__name__},
+        )
+        raise
 
 
 def get_max_cost_for_model(model: str) -> int:
-    if model not in [model.id for model in MODELS]:
+    """Get the maximum cost for a specific model."""
+    logger.debug(
+        "Getting max cost for model",
+        extra={
+            "model": model,
+            "model_based_pricing": MODEL_BASED_PRICING,
+            "has_models": bool(MODELS),
+        },
+    )
+
+    if not MODEL_BASED_PRICING or not MODELS:
+        logger.debug(
+            "Using default cost (no model-based pricing)",
+            extra={"cost_msats": COST_PER_REQUEST, "model": model},
+        )
         return COST_PER_REQUEST
+
+    if model not in [model.id for model in MODELS]:
+        logger.warning(
+            "Model not found in available models",
+            extra={
+                "requested_model": model,
+                "available_models": [m.id for m in MODELS],
+                "using_default_cost": COST_PER_REQUEST,
+            },
+        )
+        return COST_PER_REQUEST
+
     for m in MODELS:
         if m.id == model:
-            return m.sats_pricing.max_cost * 1000  # type: ignore
+            max_cost = m.sats_pricing.max_cost * 1000  # type: ignore
+            logger.debug(
+                "Found model-specific max cost",
+                extra={"model": model, "max_cost_msats": max_cost},
+            )
+            return int(max_cost)
+
+    logger.warning(
+        "Model pricing not found, using default",
+        extra={"model": model, "default_cost_msats": COST_PER_REQUEST},
+    )
     return COST_PER_REQUEST
 
 
 def create_error_response(error_type: str, message: str, status_code: int) -> Response:
     """Create a standardized error response."""
+    logger.info(
+        "Creating error response",
+        extra={
+            "error_type": error_type,
+            "error_message": message,
+            "status_code": status_code,
+        },
+    )
+
     return Response(
         content=json.dumps(
             {
@@ -93,20 +341,45 @@ def create_error_response(error_type: str, message: str, status_code: int) -> Re
 
 def prepare_upstream_headers(request_headers: dict) -> dict:
     """Prepare headers for upstream request, removing sensitive/problematic ones."""
+    logger.debug(
+        "Preparing upstream headers",
+        extra={
+            "original_headers_count": len(request_headers),
+            "has_upstream_api_key": bool(UPSTREAM_API_KEY),
+        },
+    )
+
     headers = dict(request_headers)
+
     # Remove headers that shouldn't be forwarded
-    headers.pop("host", None)
-    headers.pop("content-length", None)
-    headers.pop("refund-lnurl", None)
-    headers.pop("key-expiry-time", None)
-    headers.pop("x-cashu", None)
+    removed_headers = []
+    for header in [
+        "host",
+        "content-length",
+        "refund-lnurl",
+        "key-expiry-time",
+        "x-cashu",
+    ]:
+        if headers.pop(header, None) is not None:
+            removed_headers.append(header)
 
     # Handle authorization
     if UPSTREAM_API_KEY:
         headers["Authorization"] = f"Bearer {UPSTREAM_API_KEY}"
-        headers.pop("authorization", None)
+        if headers.pop("authorization", None) is not None:
+            removed_headers.append("authorization (replaced with upstream key)")
     else:
-        headers.pop("Authorization", None)
-        headers.pop("authorization", None)
+        for auth_header in ["Authorization", "authorization"]:
+            if headers.pop(auth_header, None) is not None:
+                removed_headers.append(auth_header)
+
+    logger.debug(
+        "Headers prepared for upstream",
+        extra={
+            "final_headers_count": len(headers),
+            "removed_headers": removed_headers,
+            "added_upstream_auth": bool(UPSTREAM_API_KEY),
+        },
+    )
 
     return headers

router/payment/x_cashu.py

@@ -1,43 +1,83 @@
 import json
 import traceback
-from typing import AsyncGenerator, Literal, cast
+from typing import AsyncGenerator
 
 import httpx
 from fastapi import BackgroundTasks, HTTPException, Request
 from fastapi.responses import Response, StreamingResponse
 
-from router.cashu import wallet
-from router.payment.cost_caculation import (
-    CostData,
-    CostDataError,
-    MaxCostData,
-    calculate_cost,
-)
-from router.payment.helpers import (
+from ..logging import get_logger
+from ..wallet import CurrencyUnit, recieve_token, send_token
+from .cost_caculation import CostData, CostDataError, MaxCostData, calculate_cost
+from .helpers import (
     UPSTREAM_BASE_URL,
     create_error_response,
     get_max_cost_for_model,
     prepare_upstream_headers,
 )
 
+logger = get_logger(__name__)
+
 
 async def x_cashu_handler(
     request: Request, x_cashu_token: str, path: str
 ) -> Response | StreamingResponse:
-    headers = dict(request.headers)
-    amount, _ = await redeem_token(x_cashu_token)
-    headers = prepare_upstream_headers(dict(request.headers))
-    return await forward_to_upstream(request, path, headers, amount)
+    """Handle X-Cashu token payment requests."""
+    logger.info(
+        "Processing X-Cashu payment request",
+        extra={
+            "path": path,
+            "method": request.method,
+            "token_preview": x_cashu_token[:20] + "..."
+            if len(x_cashu_token) > 20
+            else x_cashu_token,
+        },
+    )
+
+    try:
+        headers = dict(request.headers)
+        amount, unit, mint = await recieve_token(x_cashu_token)
+        headers = prepare_upstream_headers(dict(request.headers))
+
+        logger.info(
+            "X-Cashu token redeemed successfully",
+            extra={"amount": amount, "unit": unit, "path": path, "mint": mint},
+        )
+
+        return await forward_to_upstream(request, path, headers, amount, unit)
+    except Exception as e:
+        logger.error(
+            "X-Cashu payment request failed",
+            extra={
+                "error": str(e),
+                "error_type": type(e).__name__,
+                "path": path,
+                "method": request.method,
+            },
+        )
+        raise
 
 
 async def forward_to_upstream(
-    request: Request, path: str, headers: dict, amount: int
+    request: Request, path: str, headers: dict, amount: int, unit: CurrencyUnit
 ) -> Response | StreamingResponse:
     """Forward request to upstream and handle the response."""
     if path.startswith("v1/"):
         path = path.replace("v1/", "")
 
     url = f"{UPSTREAM_BASE_URL}/{path}"
+
+    logger.debug(
+        "Forwarding request to upstream",
+        extra={
+            "url": url,
+            "method": request.method,
+            "path": path,
+            "amount": amount,
+            "unit": unit,
+        },
+    )
+
     async with httpx.AsyncClient(
         transport=httpx.AsyncHTTPTransport(retries=1),
         timeout=None,
@@ -54,8 +94,64 @@ async def forward_to_upstream(
                 stream=True,
             )
 
+            logger.debug(
+                "Received upstream response",
+                extra={
+                    "status_code": response.status_code,
+                    "path": path,
+                    "response_headers": dict(response.headers),
+                },
+            )
+
+            if response.status_code != 200:
+                logger.warning(
+                    "Upstream request failed, processing refund",
+                    extra={
+                        "status_code": response.status_code,
+                        "path": path,
+                        "amount": amount,
+                        "unit": unit,
+                    },
+                )
+
+                refund_token = await send_refund(amount - 60, unit)
+
+                logger.info(
+                    "Refund processed for failed upstream request",
+                    extra={
+                        "status_code": response.status_code,
+                        "refund_amount": amount,
+                        "unit": unit,
+                        "refund_token_preview": refund_token[:20] + "..."
+                        if len(refund_token) > 20
+                        else refund_token,
+                    },
+                )
+
+                error_response = Response(
+                    content=json.dumps(
+                        {
+                            "error": {
+                                "message": "Error forwarding request to upstream",
+                                "type": "upstream_error",
+                                "code": response.status_code,
+                                "refund_token": refund_token,
+                            }
+                        }
+                    ),
+                    status_code=response.status_code,
+                    media_type="application/json",
+                )
+                error_response.headers["X-Cashu"] = refund_token
+                return error_response
+
             if path.endswith("chat/completions"):
-                result = await handle_x_cashu_chat_completion(response, amount)
+                logger.debug(
+                    "Processing chat completion response",
+                    extra={"path": path, "amount": amount, "unit": unit},
+                )
+
+                result = await handle_x_cashu_chat_completion(response, amount, unit)
                 background_tasks = BackgroundTasks()
                 background_tasks.add_task(response.aclose)
                 result.background = background_tasks
@@ -65,6 +161,11 @@ async def forward_to_upstream(
             background_tasks.add_task(response.aclose)
             background_tasks.add_task(client.aclose)
 
+            logger.debug(
+                "Streaming non-chat response",
+                extra={"path": path, "status_code": response.status_code},
+            )
+
             return StreamingResponse(
                 response.aiter_bytes(),
                 status_code=response.status_code,
@@ -73,11 +174,17 @@ async def forward_to_upstream(
             )
         except Exception as exc:
             tb = traceback.format_exc()
-            print(
-                f"Unexpected error: {exc}\n"
-                f"Request details: method={request.method}, url={url}, headers={headers}, "
-                f"path={path}, query_params={dict(request.query_params)}\n"
-                f"Traceback:\n{tb}"
+            logger.error(
+                "Unexpected error in upstream forwarding",
+                extra={
+                    "error": str(exc),
+                    "error_type": type(exc).__name__,
+                    "method": request.method,
+                    "url": url,
+                    "path": path,
+                    "query_params": dict(request.query_params),
+                    "traceback": tb,
+                },
             )
             return create_error_response(
                 "internal_error", "An unexpected server error occurred", 500
@@ -85,23 +192,46 @@ async def forward_to_upstream(
 
 
 async def handle_x_cashu_chat_completion(
-    response: httpx.Response, amount: int
+    response: httpx.Response, amount: int, unit: CurrencyUnit
 ) -> StreamingResponse | Response:
     """Handle both streaming and non-streaming chat completion responses with token-based pricing."""
+    logger.debug(
+        "Handling chat completion response",
+        extra={"amount": amount, "unit": unit, "status_code": response.status_code},
+    )
+
     try:
         content = await response.aread()
         content_str = content.decode("utf-8") if isinstance(content, bytes) else content
         is_streaming = content_str.startswith("data:") or "data:" in content_str
 
+        logger.debug(
+            "Chat completion response analysis",
+            extra={
+                "is_streaming": is_streaming,
+                "content_length": len(content_str),
+                "amount": amount,
+                "unit": unit,
+            },
+        )
+
         if is_streaming:
-            print("Detected streaming response, processing SSE format")
-            return await handle_streaming_response(content_str, response, amount)
+            return await handle_streaming_response(content_str, response, amount, unit)
         else:
-            print("Detected non-streaming response, processing as JSON")
-            return await handle_non_streaming_response(content_str, response, amount)
+            return await handle_non_streaming_response(
+                content_str, response, amount, unit
+            )
 
     except Exception as e:
-        print(f"Error processing chat completion response: {e}")
+        logger.error(
+            "Error processing chat completion response",
+            extra={
+                "error": str(e),
+                "error_type": type(e).__name__,
+                "amount": amount,
+                "unit": unit,
+            },
+        )
         # Return the original response if we can't process it
         return StreamingResponse(
             response.aiter_bytes(),
@@ -111,9 +241,25 @@ async def handle_x_cashu_chat_completion(
 
 
 async def handle_streaming_response(
-    content_str: str, response: httpx.Response, amount: int
+    content_str: str, response: httpx.Response, amount: int, unit: CurrencyUnit
 ) -> StreamingResponse:
     """Handle Server-Sent Events (SSE) streaming response."""
+    logger.debug(
+        "Processing streaming response",
+        extra={
+            "amount": amount,
+            "unit": unit,
+            "content_lines": len(content_str.strip().split("\n")),
+        },
+    )
+
+    # Initialize response headers early so they can be modified during processing
+    response_headers = dict(response.headers)
+    if "transfer-encoding" in response_headers:
+        del response_headers["transfer-encoding"]
+    if "content-encoding" in response_headers:
+        del response_headers["content-encoding"]
+
     # For streaming responses, we'll extract the final usage data
     # and calculate cost based on that
     usage_data = None
@@ -134,27 +280,69 @@ async def handle_streaming_response(
             except json.JSONDecodeError:
                 continue
 
-    print(f"usage: {usage_data}")
+    response_headers = dict(response.headers)
     # If we found usage data, calculate cost and refund
     if usage_data and model:
+        logger.debug(
+            "Found usage data in streaming response",
+            extra={
+                "model": model,
+                "usage_data": usage_data,
+                "amount": amount,
+                "unit": unit,
+            },
+        )
+
         response_data = {"usage": usage_data, "model": model}
         try:
             cost_data = await get_cost(response_data)
-            print(f"Refunded {cost_data} msats")
             if cost_data:
                 refund_amount = amount - cost_data.total_msats
                 if refund_amount > 0:
-                    refund_token = await send_refund(refund_amount)
-                    response.headers["X-Cashu"] = refund_token
-                    print(f"Refunded {refund_amount} msats")
-        except Exception as e:
-            print(f"Error calculating cost for streaming response: {e}")
+                    logger.info(
+                        "Processing refund for streaming response",
+                        extra={
+                            "original_amount": amount,
+                            "cost_msats": cost_data.total_msats,
+                            "refund_amount": refund_amount,
+                            "unit": unit,
+                            "model": model,
+                        },
+                    )
 
-    response_headers = dict(response.headers)
-    if "transfer-encoding" in response_headers:
-        del response_headers["transfer-encoding"]
-    if "content-encoding" in response_headers:
-        del response_headers["content-encoding"]
+                    refund_token = await send_refund(refund_amount, unit)
+                    response_headers["X-Cashu"] = refund_token
+
+                    logger.info(
+                        "Refund processed for streaming response",
+                        extra={
+                            "refund_amount": refund_amount,
+                            "unit": unit,
+                            "refund_token_preview": refund_token[:20] + "..."
+                            if len(refund_token) > 20
+                            else refund_token,
+                        },
+                    )
+                else:
+                    logger.debug(
+                        "No refund needed for streaming response",
+                        extra={
+                            "amount": amount,
+                            "cost_msats": cost_data.total_msats,
+                            "model": model,
+                        },
+                    )
+        except Exception as e:
+            logger.error(
+                "Error calculating cost for streaming response",
+                extra={
+                    "error": str(e),
+                    "error_type": type(e).__name__,
+                    "model": model,
+                    "amount": amount,
+                    "unit": unit,
+                },
+            )
 
     async def generate() -> AsyncGenerator[bytes, None]:
         for line in lines:
@@ -169,15 +357,28 @@ async def handle_streaming_response(
 
 
 async def handle_non_streaming_response(
-    content_str: str, response: httpx.Response, amount: int
+    content_str: str, response: httpx.Response, amount: int, unit: CurrencyUnit
 ) -> Response:
     """Handle regular JSON response."""
+    logger.debug(
+        "Processing non-streaming response",
+        extra={"amount": amount, "unit": unit, "content_length": len(content_str)},
+    )
+
     try:
         response_json = json.loads(content_str)
 
         cost_data = await get_cost(response_json)
 
         if not cost_data:
+            logger.error(
+                "Failed to calculate cost for response",
+                extra={
+                    "amount": amount,
+                    "unit": unit,
+                    "response_model": response_json.get("model", "unknown"),
+                },
+            )
             return Response(
                 content=json.dumps(
                     {
@@ -199,11 +400,32 @@ async def handle_non_streaming_response(
             del response_headers["content-encoding"]
 
         refund_amount = amount - cost_data.total_msats
-        print("refund: ", refund_amount)
+
+        logger.info(
+            "Processing non-streaming response cost calculation",
+            extra={
+                "original_amount": amount,
+                "cost_msats": cost_data.total_msats,
+                "refund_amount": refund_amount,
+                "unit": unit,
+                "model": response_json.get("model", "unknown"),
+            },
+        )
+
         if refund_amount > 0:
-            refund_token = await send_refund(refund_amount)
-            response.headers["X-Cashu"] = refund_token
-            print(f"Refunded {refund_amount} msats")
+            refund_token = await send_refund(refund_amount, unit)
+            response_headers["X-Cashu"] = refund_token
+
+            logger.info(
+                "Refund processed for non-streaming response",
+                extra={
+                    "refund_amount": refund_amount,
+                    "unit": unit,
+                    "refund_token_preview": refund_token[:20] + "..."
+                    if len(refund_token) > 20
+                    else refund_token,
+                },
+            )
 
         return Response(
             content=content_str,
@@ -212,8 +434,32 @@ async def handle_non_streaming_response(
             media_type="application/json",
         )
     except json.JSONDecodeError as e:
-        response.headers["X-Cashu"] = await wallet().send(amount - 60)
-        print(f"Failed to parse JSON from upstream response: {e}")
+        logger.error(
+            "Failed to parse JSON from upstream response",
+            extra={
+                "error": str(e),
+                "content_preview": content_str[:200] + "..."
+                if len(content_str) > 200
+                else content_str,
+                "amount": amount,
+                "unit": unit,
+            },
+        )
+
+        # Emergency refund with small deduction for processing
+        emergency_refund = amount
+        refund_token = await send_token(emergency_refund, unit=unit)
+        response.headers["X-Cashu"] = refund_token
+
+        logger.warning(
+            "Emergency refund issued due to JSON parse error",
+            extra={
+                "original_amount": amount,
+                "refund_amount": emergency_refund,
+                "deduction": 60,
+            },
+        )
+
         # Return original content if JSON parsing fails
         return Response(
             content=content_str,
@@ -229,14 +475,41 @@ async def get_cost(response_data: dict) -> MaxCostData | CostData | None:
     This is called after the initial payment and the upstream request is complete.
     Returns cost data to be included in the response.
     """
-    max_cost = get_max_cost_for_model(model=response_data["model"])
+    model = response_data.get("model", "unknown")
+    logger.debug(
+        "Calculating cost for response",
+        extra={"model": model, "has_usage": "usage" in response_data},
+    )
+
+    max_cost = get_max_cost_for_model(model=model)
 
     match calculate_cost(response_data, max_cost):
         case MaxCostData() as cost:
+            logger.debug(
+                "Using max cost pricing",
+                extra={"model": model, "max_cost_msats": cost.total_msats},
+            )
             return cost
         case CostData() as cost:
+            logger.debug(
+                "Using token-based pricing",
+                extra={
+                    "model": model,
+                    "total_cost_msats": cost.total_msats,
+                    "input_msats": cost.input_msats,
+                    "output_msats": cost.output_msats,
+                },
+            )
             return cost
         case CostDataError() as error:
+            logger.error(
+                "Cost calculation error",
+                extra={
+                    "model": model,
+                    "error_message": error.message,
+                    "error_code": error.code,
+                },
+            )
             raise HTTPException(
                 status_code=400,
                 detail={
@@ -249,34 +522,70 @@ async def get_cost(response_data: dict) -> MaxCostData | CostData | None:
             )
 
 
-async def redeem_token(x_cashu_token: str) -> tuple[int, Literal["sat", "msat"]]:
-    try:
-        result = await wallet().redeem(x_cashu_token)
-        return cast(tuple[int, Literal["sat", "msat"]], result)
-    except Exception as e:
-        raise HTTPException(
-            status_code=401,
-            detail={
-                "error": {
-                    "message": f"Invalid or expired Cashu key: {str(e)}",
-                    "type": "invalid_request_error",
-                    "code": "invalid_api_key",
-                }
-            },
-        )
+async def send_refund(amount: int, unit: CurrencyUnit, mint: str | None = None) -> str:
+    """Send a refund using Cashu tokens."""
+    logger.debug(
+        "Creating refund token", extra={"amount": amount, "unit": unit, "mint": mint}
+    )
 
+    max_retries = 3
+    last_exception = None
 
-async def send_refund(amount: int) -> str:
-    try:
-        return await wallet().send(amount)
-    except Exception as e:
-        raise HTTPException(
-            status_code=401,
-            detail={
-                "error": {
-                    "message": f"failed to create refund: {str(e)}",
-                    "type": "invalid_request_error",
-                    "code": "send_token_failed",
-                }
-            },
-        )
+    for attempt in range(max_retries):
+        try:
+            refund_token = await send_token(amount, unit=unit, mint_url=mint)
+
+            logger.info(
+                "Refund token created successfully",
+                extra={
+                    "amount": amount,
+                    "unit": unit,
+                    "mint": mint,
+                    "attempt": attempt + 1,
+                    "token_preview": refund_token[:20] + "..."
+                    if len(refund_token) > 20
+                    else refund_token,
+                },
+            )
+
+            return refund_token
+        except Exception as e:
+            last_exception = e
+            if attempt < max_retries - 1:
+                logger.warning(
+                    "Refund token creation failed, retrying",
+                    extra={
+                        "error": str(e),
+                        "error_type": type(e).__name__,
+                        "attempt": attempt + 1,
+                        "max_retries": max_retries,
+                        "amount": amount,
+                        "unit": unit,
+                        "mint": mint,
+                    },
+                )
+            else:
+                logger.error(
+                    "Failed to create refund token after all retries",
+                    extra={
+                        "error": str(e),
+                        "error_type": type(e).__name__,
+                        "attempt": attempt + 1,
+                        "max_retries": max_retries,
+                        "amount": amount,
+                        "unit": unit,
+                        "mint": mint,
+                    },
+                )
+
+    # If we get here, all retries failed
+    raise HTTPException(
+        status_code=401,
+        detail={
+            "error": {
+                "message": f"failed to create refund after {max_retries} attempts: {str(last_exception)}",
+                "type": "invalid_request_error",
+                "code": "send_token_failed",
+            }
+        },
+    )

router/price.py

@@ -1,57 +1,128 @@
 import asyncio
-import logging
 import os
 
 import httpx
 
+from .logging import get_logger
+
+logger = get_logger(__name__)
+
 # artifical spread to cover conversion fees
 EXCHANGE_FEE = float(os.environ.get("EXCHANGE_FEE", "1.005"))  # 0.5% default
 
+logger.info("Price module initialized", extra={"exchange_fee": EXCHANGE_FEE})
+
 
 async def kraken_btc_usd(client: httpx.AsyncClient) -> float | None:
+    """Fetch BTC/USD price from Kraken API."""
     api = "https://api.kraken.com/0/public/Ticker?pair=XBTUSD"
     try:
-        return float((await client.get(api)).json()["result"]["XXBTZUSD"]["c"][0])
+        logger.debug("Fetching BTC price from Kraken")
+        response = await client.get(api)
+        price_data = response.json()
+        price = float(price_data["result"]["XXBTZUSD"]["c"][0])
+
+        return price
     except (httpx.RequestError, KeyError) as e:
-        logging.warning(f"Kraken API error: {e}")
+        logger.warning(
+            "Kraken API error",
+            extra={
+                "error": str(e),
+                "error_type": type(e).__name__,
+                "exchange": "kraken",
+            },
+        )
         return None
 
 
 async def coinbase_btc_usd(client: httpx.AsyncClient) -> float | None:
+    """Fetch BTC/USD price from Coinbase API."""
     api = "https://api.coinbase.com/v2/prices/BTC-USD/spot"
     try:
-        return float((await client.get(api)).json()["data"]["amount"])
+        logger.debug("Fetching BTC price from Coinbase")
+        response = await client.get(api)
+        price_data = response.json()
+        price = float(price_data["data"]["amount"])
+
+        return price
     except (httpx.RequestError, KeyError) as e:
-        logging.warning(f"Coinbase API error: {e}")
+        logger.warning(
+            "Coinbase API error",
+            extra={
+                "error": str(e),
+                "error_type": type(e).__name__,
+                "exchange": "coinbase",
+            },
+        )
         return None
 
 
 async def binance_btc_usdt(client: httpx.AsyncClient) -> float | None:
+    """Fetch BTC/USDT price from Binance API."""
     api = "https://api.binance.com/api/v3/ticker/price?symbol=BTCUSDT"
     try:
-        return float((await client.get(api)).json()["price"])
+        logger.debug("Fetching BTC price from Binance")
+        response = await client.get(api)
+        price_data = response.json()
+        price = float(price_data["price"])
+
+        return price
     except (httpx.RequestError, KeyError) as e:
-        logging.warning(f"Binance API error: {e}")
+        logger.warning(
+            "Binance API error",
+            extra={
+                "error": str(e),
+                "error_type": type(e).__name__,
+                "exchange": "binance",
+            },
+        )
         return None
 
 
 async def btc_usd_ask_price() -> float:
-    async with httpx.AsyncClient() as client:
-        return (
-            max(
-                [
-                    price
-                    for price in await asyncio.gather(
-                        kraken_btc_usd(client),
-                        coinbase_btc_usd(client),
-                        binance_btc_usdt(client),
-                    )
-                    if price is not None
-                ]
+    """Get the highest BTC/USD price from multiple exchanges with fee adjustment."""
+    logger.debug("Starting BTC price aggregation from multiple exchanges")
+
+    async with httpx.AsyncClient(timeout=30.0) as client:
+        try:
+            prices = await asyncio.gather(
+                kraken_btc_usd(client),
+                coinbase_btc_usd(client),
+                binance_btc_usdt(client),
             )
-            * EXCHANGE_FEE
-        )
+
+            valid_prices = [price for price in prices if price is not None]
+
+            if not valid_prices:
+                logger.error("No valid BTC prices obtained from any exchange")
+                raise ValueError("Unable to fetch BTC price from any exchange")
+
+            max_price = max(valid_prices)
+            final_price = max_price * EXCHANGE_FEE
+
+            return final_price
+
+        except Exception as e:
+            logger.error(
+                "Error in BTC price aggregation",
+                extra={"error": str(e), "error_type": type(e).__name__},
+            )
+            raise
 
 
 async def sats_usd_ask_price() -> float:
-    return (await btc_usd_ask_price()) / 100_000_000
+    """Get the USD price per satoshi."""
+    logger.debug("Calculating satoshi price from BTC price")
+
+    try:
+        btc_price = await btc_usd_ask_price()
+        sats_price = btc_price / 100_000_000
+
+        return sats_price
+
+    except Exception as e:
+        logger.error(
+            "Error calculating satoshi price",
+            extra={"error": str(e), "error_type": type(e).__name__},
+        )
+        raise

router/proxy.py

@@ -7,18 +7,23 @@ import httpx
 from fastapi import APIRouter, BackgroundTasks, Depends, HTTPException, Request
 from fastapi.responses import Response, StreamingResponse
 
-from router.payment.helpers import (
+from .auth import (
+    adjust_payment_for_tokens,
+    pay_for_request,
+    revert_pay_for_request,
+    validate_bearer_key,
+)
+from .db import ApiKey, AsyncSession, create_session, get_session
+from .logging import get_logger
+from .payment.helpers import (
     UPSTREAM_BASE_URL,
     check_token_balance,
     create_error_response,
     prepare_upstream_headers,
 )
-from router.payment.x_cashu import x_cashu_handler
-
-from .auth import adjust_payment_for_tokens, pay_for_request, validate_bearer_key
-from .cashu import x_cashu_refund
-from .db import ApiKey, AsyncSession, create_session, get_session
+from .payment.x_cashu import x_cashu_handler
 
+logger = get_logger(__name__)
 proxy_router = APIRouter()
 
 
@@ -26,6 +31,14 @@ async def handle_streaming_chat_completion(
     response: httpx.Response, key: ApiKey, session: AsyncSession
 ) -> StreamingResponse:
     """Handle streaming chat completion responses with token-based pricing."""
+    logger.info(
+        "Processing streaming chat completion",
+        extra={
+            "key_hash": key.hashed_key[:8] + "...",
+            "key_balance": key.balance,
+            "response_status": response.status_code,
+        },
+    )
 
     async def stream_with_cost() -> AsyncGenerator[bytes, None]:
         # Store all chunks to analyze
@@ -38,6 +51,14 @@ async def handle_streaming_chat_completion(
             # Pass through each chunk to client
             yield chunk
 
+        logger.debug(
+            "Streaming completed, analyzing usage data",
+            extra={
+                "key_hash": key.hashed_key[:8] + "...",
+                "chunks_count": len(stored_chunks),
+            },
+        )
+
         # Process stored chunks to find usage data
         # Start from the end and work backwards
         for i in range(len(stored_chunks) - 1, -1, -1):
@@ -63,6 +84,15 @@ async def handle_streaming_chat_completion(
                             and data["usage"] is not None
                             and isinstance(data["usage"], dict)
                         ):
+                            logger.info(
+                                "Found usage data in streaming response",
+                                extra={
+                                    "key_hash": key.hashed_key[:8] + "...",
+                                    "usage_data": data["usage"],
+                                    "model": data.get("model", "unknown"),
+                                },
+                            )
+
                             # Found usage data, calculate cost
                             # Create a new session for this operation
                             async with create_session() as new_session:
@@ -71,18 +101,43 @@ async def handle_streaming_chat_completion(
                                     key.__class__, key.hashed_key
                                 )
                                 if fresh_key:
-                                    cost_data = await adjust_payment_for_tokens(
-                                        fresh_key, data, new_session
-                                    )
-                                    # Format as SSE and yield
-                                    cost_json = json.dumps({"cost": cost_data})
-                                    yield f"data: {cost_json}\n\n".encode()
+                                    try:
+                                        cost_data = await adjust_payment_for_tokens(
+                                            fresh_key, data, new_session
+                                        )
+                                        logger.info(
+                                            "Token adjustment completed for streaming",
+                                            extra={
+                                                "key_hash": key.hashed_key[:8] + "...",
+                                                "cost_data": cost_data,
+                                                "balance_after_adjustment": fresh_key.balance,
+                                            },
+                                        )
+                                        # Format as SSE and yield
+                                        cost_json = json.dumps({"cost": cost_data})
+                                        yield f"data: {cost_json}\n\n".encode()
+                                    except Exception as cost_error:
+                                        logger.error(
+                                            "Error adjusting payment for streaming tokens",
+                                            extra={
+                                                "error": str(cost_error),
+                                                "error_type": type(cost_error).__name__,
+                                                "key_hash": key.hashed_key[:8] + "...",
+                                            },
+                                        )
                             break
                     except json.JSONDecodeError:
                         continue
 
             except Exception as e:
-                print(f"Error processing streaming response for cost: {e}")
+                logger.error(
+                    "Error processing streaming response chunk",
+                    extra={
+                        "error": str(e),
+                        "error_type": type(e).__name__,
+                        "key_hash": key.hashed_key[:8] + "...",
+                    },
+                )
 
     return StreamingResponse(
         stream_with_cost(),
@@ -95,21 +150,58 @@ async def handle_non_streaming_chat_completion(
     response: httpx.Response, key: ApiKey, session: AsyncSession
 ) -> Response:
     """Handle non-streaming chat completion responses with token-based pricing."""
+    logger.info(
+        "Processing non-streaming chat completion",
+        extra={
+            "key_hash": key.hashed_key[:8] + "...",
+            "key_balance": key.balance,
+            "response_status": response.status_code,
+        },
+    )
+
     try:
         content = await response.aread()
         response_json = json.loads(content)
+
+        logger.debug(
+            "Parsed response JSON",
+            extra={
+                "key_hash": key.hashed_key[:8] + "...",
+                "model": response_json.get("model", "unknown"),
+                "has_usage": "usage" in response_json,
+            },
+        )
+
         cost_data = await adjust_payment_for_tokens(key, response_json, session)
         response_json["cost"] = cost_data
 
-        response_headers = dict(response.headers)
+        logger.info(
+            "Token adjustment completed for non-streaming",
+            extra={
+                "key_hash": key.hashed_key[:8] + "...",
+                "cost_data": cost_data,
+                "model": response_json.get("model", "unknown"),
+                "balance_after_adjustment": key.balance,
+            },
+        )
 
-        # Remove Transfer-Encoding header to avoid conflict with Content-Length header in common nginx setups
-        if "transfer-encoding" in response_headers:
-            del response_headers["transfer-encoding"]
+        # Keep only standard headers that are safe to pass through
+        allowed_headers = {
+            "content-type",
+            "cache-control",
+            "date",
+            "vary",
+            "access-control-allow-origin",
+            "access-control-allow-methods",
+            "access-control-allow-headers",
+            "access-control-allow-credentials",
+            "access-control-expose-headers",
+            "access-control-max-age",
+        }
 
-        # Remove Content-Encoding header since we're sending uncompressed JSON
-        if "content-encoding" in response_headers:
-            del response_headers["content-encoding"]
+        response_headers = {
+            k: v for k, v in response.headers.items() if k.lower() in allowed_headers
+        }
 
         return Response(
             content=json.dumps(response_json).encode(),
@@ -118,10 +210,26 @@ async def handle_non_streaming_chat_completion(
             media_type="application/json",
         )
     except json.JSONDecodeError as e:
-        print(f"Failed to parse JSON from upstream response: {e}")
+        logger.error(
+            "Failed to parse JSON from upstream response",
+            extra={
+                "error": str(e),
+                "key_hash": key.hashed_key[:8] + "...",
+                "content_preview": content[:200].decode(errors="ignore")
+                if content
+                else "empty",
+            },
+        )
         raise
     except Exception as e:
-        print(f"Error adjusting payment for tokens: {e}")
+        logger.error(
+            "Error processing non-streaming chat completion",
+            extra={
+                "error": str(e),
+                "error_type": type(e).__name__,
+                "key_hash": key.hashed_key[:8] + "...",
+            },
+        )
         raise
 
 
@@ -138,6 +246,19 @@ async def forward_to_upstream(
         path = path.replace("v1/", "")
 
     url = f"{UPSTREAM_BASE_URL}/{path}"
+
+    logger.info(
+        "Forwarding request to upstream",
+        extra={
+            "url": url,
+            "method": request.method,
+            "path": path,
+            "key_hash": key.hashed_key[:8] + "...",
+            "key_balance": key.balance,
+            "has_request_body": request_body is not None,
+        },
+    )
+
     client = httpx.AsyncClient(
         transport=httpx.AsyncHTTPTransport(retries=1),
         timeout=None,  # No timeout - requests can take as long as needed
@@ -168,11 +289,52 @@ async def forward_to_upstream(
                 stream=True,
             )
 
+        logger.info(
+            "Received upstream response",
+            extra={
+                "status_code": response.status_code,
+                "path": path,
+                "key_hash": key.hashed_key[:8] + "...",
+                "content_type": response.headers.get("content-type", "unknown"),
+            },
+        )
+
         # For chat completions, we need to handle token-based pricing
         if path.endswith("chat/completions"):
+            # Check if client requested streaming
+            client_wants_streaming = False
+            if request_body:
+                try:
+                    request_data = json.loads(request_body)
+                    client_wants_streaming = request_data.get("stream", False)
+                    logger.debug(
+                        "Chat completion request analysis",
+                        extra={
+                            "client_wants_streaming": client_wants_streaming,
+                            "model": request_data.get("model", "unknown"),
+                            "key_hash": key.hashed_key[:8] + "...",
+                        },
+                    )
+                except json.JSONDecodeError:
+                    logger.warning(
+                        "Failed to parse request body JSON for streaming detection"
+                    )
+
             # Handle both streaming and non-streaming responses
             content_type = response.headers.get("content-type", "")
-            is_streaming = "text/event-stream" in content_type
+            upstream_is_streaming = "text/event-stream" in content_type
+            is_streaming = client_wants_streaming and upstream_is_streaming
+
+            logger.debug(
+                "Response type analysis",
+                extra={
+                    "is_streaming": is_streaming,
+                    "client_wants_streaming": client_wants_streaming,
+                    "upstream_is_streaming": upstream_is_streaming,
+                    "content_type": content_type,
+                    "key_hash": key.hashed_key[:8] + "...",
+                },
+            )
 
             if is_streaming and response.status_code == 200:
                 # Process streaming response and extract cost from the last chunk
@@ -183,7 +345,7 @@ async def forward_to_upstream(
                 result.background = background_tasks
                 return result
 
-            elif response.status_code == 200 and "application/json" in content_type:
+            elif response.status_code == 200:
                 # Handle non-streaming response
                 try:
                     return await handle_non_streaming_chat_completion(
@@ -198,6 +360,15 @@ async def forward_to_upstream(
         background_tasks.add_task(response.aclose)
         background_tasks.add_task(client.aclose)
 
+        logger.debug(
+            "Streaming non-chat response",
+            extra={
+                "path": path,
+                "status_code": response.status_code,
+                "key_hash": key.hashed_key[:8] + "...",
+            },
+        )
+
         return StreamingResponse(
             response.aiter_bytes(),
             status_code=response.status_code,
@@ -209,10 +380,18 @@ async def forward_to_upstream(
         await client.aclose()
         error_type = type(exc).__name__
         error_details = str(exc)
-        print(
-            f"Error forwarding request to upstream: {error_type}: {error_details}\n"
-            f"Request details: method={request.method}, url={url}, headers={headers}, "
-            f"path={path}, query_params={dict(request.query_params)}"
+
+        logger.error(
+            "HTTP request error to upstream",
+            extra={
+                "error_type": error_type,
+                "error_details": error_details,
+                "method": request.method,
+                "url": url,
+                "path": path,
+                "query_params": dict(request.query_params),
+                "key_hash": key.hashed_key[:8] + "...",
+            },
         )
 
         # Provide more specific error messages based on the error type
@@ -229,15 +408,22 @@ async def forward_to_upstream(
 
     except Exception as exc:
         await client.aclose()
-        import traceback
-
         tb = traceback.format_exc()
-        print(
-            f"Unexpected error: {exc}\n"
-            f"Request details: method={request.method}, url={url}, headers={headers}, "
-            f"path={path}, query_params={dict(request.query_params)}\n"
-            f"Traceback:\n{tb}"
+
+        logger.error(
+            "Unexpected error in upstream forwarding",
+            extra={
+                "error": str(exc),
+                "error_type": type(exc).__name__,
+                "method": request.method,
+                "url": url,
+                "path": path,
+                "query_params": dict(request.query_params),
+                "key_hash": key.hashed_key[:8] + "...",
+                "traceback": tb,
+            },
         )
+
         return create_error_response(
             "internal_error", "An unexpected server error occurred", 500
         )
@@ -247,6 +433,17 @@ async def forward_to_upstream(
 async def proxy(
     request: Request, path: str, session: AsyncSession = Depends(get_session)
 ) -> Response | StreamingResponse:
+    """Main proxy endpoint handler."""
+    logger.info(
+        "Received proxy request",
+        extra={
+            "method": request.method,
+            "path": path,
+            "client_host": request.client.host if request.client else "unknown",
+            "user_agent": request.headers.get("user-agent", "unknown")[:100],
+        },
+    )
+
     request_body = await request.body()
     headers = dict(request.headers)
 
@@ -255,7 +452,25 @@ async def proxy(
     if request_body:
         try:
             request_body_dict = json.loads(request_body)
-        except json.JSONDecodeError:
+            logger.debug(
+                "Request body parsed",
+                extra={
+                    "path": path,
+                    "body_keys": list(request_body_dict.keys()),
+                    "model": request_body_dict.get("model", "not_specified"),
+                },
+            )
+        except json.JSONDecodeError as e:
+            logger.error(
+                "Invalid JSON in request body",
+                extra={
+                    "error": str(e),
+                    "path": path,
+                    "body_preview": request_body[:200].decode(errors="ignore")
+                    if request_body
+                    else "empty",
+                },
+            )
             return Response(
                 content=json.dumps(
                     {"error": {"type": "invalid_request_error", "code": "invalid_json"}}
@@ -264,31 +479,92 @@ async def proxy(
                 media_type="application/json",
             )
 
+    # Check token balance for all requests to get currency unit
+    try:
+        unit = check_token_balance(headers, request_body_dict)
+        logger.debug(
+            "Token balance check completed", extra={"path": path, "unit": unit}
+        )
+    except HTTPException as e:
+        logger.warning(
+            "Token balance check failed",
+            extra={"path": path, "status_code": e.status_code, "detail": str(e.detail)},
+        )
+        raise
+
     # Handle authentication
     if x_cashu := headers.get("x-cashu", None):
-        # Check token balance before authentication for cashu tokens
-        if request_body_dict:
-            check_token_balance(headers, request_body_dict, "msat")
+        logger.info(
+            "Processing X-Cashu payment",
+            extra={
+                "path": path,
+                "token_preview": x_cashu[:20] + "..." if len(x_cashu) > 20 else x_cashu,
+            },
+        )
         return await x_cashu_handler(request, x_cashu, path)
 
     elif auth := headers.get("authorization", None):
+        logger.debug(
+            "Processing bearer token authentication",
+            extra={
+                "path": path,
+                "token_preview": auth[:20] + "..." if len(auth) > 20 else auth,
+            },
+        )
         key = await get_bearer_token_key(headers, path, session, auth)
 
     else:
         if request.method not in ["GET"]:
+            logger.warning(
+                "Unauthorized request - no authentication provided",
+                extra={"method": request.method, "path": path},
+            )
             return Response(
                 content=json.dumps({"detail": "Unauthorized"}),
                 status_code=401,
                 media_type="application/json",
             )
 
+        logger.debug("Processing unauthenticated GET request", extra={"path": path})
         # Prepare headers for upstream
         headers = prepare_upstream_headers(dict(request.headers))
         return await forward_get_to_upstream(request, path, headers)
 
+    cost_per_request = 0
     # Only pay for request if we have request body data (for completions endpoints)
     if request_body_dict:
-        await pay_for_request(key, session, request_body_dict)
+        logger.info(
+            "Processing payment for request",
+            extra={
+                "path": path,
+                "key_hash": key.hashed_key[:8] + "...",
+                "key_balance_before": key.balance,
+                "model": request_body_dict.get("model", "unknown"),
+            },
+        )
+
+        try:
+            await pay_for_request(key, session, request_body_dict)
+            logger.info(
+                "Payment processed successfully",
+                extra={
+                    "path": path,
+                    "key_hash": key.hashed_key[:8] + "...",
+                    "key_balance_after": key.balance,
+                    "model": request_body_dict.get("model", "unknown"),
+                },
+            )
+        except Exception as e:
+            logger.error(
+                "Payment processing failed",
+                extra={
+                    "error": str(e),
+                    "error_type": type(e).__name__,
+                    "path": path,
+                    "key_hash": key.hashed_key[:8] + "...",
+                },
+            )
+            raise
 
     # Prepare headers for upstream
     headers = prepare_upstream_headers(dict(request.headers))
@@ -298,28 +574,17 @@ async def proxy(
         request, path, headers, request_body, key, session
     )
 
-    if response.status_code != 200 and key.refund_address == "X-CASHU":
-        refund_token = await x_cashu_refund(key, session)
-        response = Response(
-            content=json.dumps(
-                {
-                    "error": {
-                        "message": "Error forwarding request to upstream",
-                        "type": "upstream_error",
-                        "code": response.status_code,
-                        "refund_token": refund_token,
-                    }
-                }
-            ),
-            status_code=response.status_code,
-            media_type="application/json",
+    if response.status_code != 200:
+        await revert_pay_for_request(key, session, cost_per_request)
+        logger.warning(
+            "Upstream request failed, revert payment",
+            extra={
+                "status_code": response.status_code,
+                "path": path,
+                "key_hash": key.hashed_key[:8] + "...",
+                "key_balance": key.balance,
+            },
         )
-        response.headers["X-Cashu"] = refund_token
-        return response
-
-    if key.refund_address == "X-CASHU":
-        refund_token = await x_cashu_refund(key, session)
-        response.headers["X-Cashu"] = refund_token
 
     return response
 
@@ -332,16 +597,40 @@ async def get_bearer_token_key(
     refund_address = headers.get("Refund-LNURL", None)
     key_expiry_time = headers.get("Key-Expiry-Time", None)
 
+    logger.debug(
+        "Processing bearer token",
+        extra={
+            "path": path,
+            "has_refund_address": bool(refund_address),
+            "has_expiry_time": bool(key_expiry_time),
+            "bearer_key_preview": bearer_key[:20] + "..."
+            if len(bearer_key) > 20
+            else bearer_key,
+        },
+    )
+
     # Validate key_expiry_time header
     if key_expiry_time:
         try:
             key_expiry_time = int(key_expiry_time)  # type: ignore
+            logger.debug(
+                "Key expiry time validated",
+                extra={"expiry_time": key_expiry_time, "path": path},
+            )
         except ValueError:
+            logger.error(
+                "Invalid Key-Expiry-Time header",
+                extra={"key_expiry_time": key_expiry_time, "path": path},
+            )
             raise HTTPException(
                 status_code=400,
                 detail="Invalid Key-Expiry-Time: must be a valid Unix timestamp",
             )
         if not refund_address:
+            logger.error(
+                "Missing Refund-LNURL header with Key-Expiry-Time",
+                extra={"path": path, "expiry_time": key_expiry_time},
+            )
             raise HTTPException(
                 status_code=400,
                 detail="Error: Refund-LNURL header required when using Key-Expiry-Time",
@@ -349,12 +638,35 @@ async def get_bearer_token_key(
     else:
         key_expiry_time = None
 
-    return await validate_bearer_key(
-        bearer_key,
-        session,
-        refund_address,
-        key_expiry_time,  # type: ignore
-    )
+    try:
+        key = await validate_bearer_key(
+            bearer_key,
+            session,
+            refund_address,
+            key_expiry_time,  # type: ignore
+        )
+        logger.info(
+            "Bearer token validated successfully",
+            extra={
+                "path": path,
+                "key_hash": key.hashed_key[:8] + "...",
+                "key_balance": key.balance,
+            },
+        )
+        return key
+    except Exception as e:
+        logger.error(
+            "Bearer token validation failed",
+            extra={
+                "error": str(e),
+                "error_type": type(e).__name__,
+                "path": path,
+                "bearer_key_preview": bearer_key[:20] + "..."
+                if len(bearer_key) > 20
+                else bearer_key,
+            },
+        )
+        raise
 
 
 async def forward_get_to_upstream(
@@ -368,6 +680,11 @@ async def forward_get_to_upstream(
 
     url = f"{UPSTREAM_BASE_URL}/{path}"
 
+    logger.info(
+        "Forwarding GET request to upstream",
+        extra={"url": url, "method": request.method, "path": path},
+    )
+
     async with httpx.AsyncClient(
         transport=httpx.AsyncHTTPTransport(retries=1),
         timeout=None,
@@ -383,6 +700,11 @@ async def forward_get_to_upstream(
                 ),
             )
 
+            logger.info(
+                "GET request forwarded successfully",
+                extra={"path": path, "status_code": response.status_code},
+            )
+
             return StreamingResponse(
                 response.aiter_bytes(),
                 status_code=response.status_code,
@@ -390,11 +712,17 @@ async def forward_get_to_upstream(
             )
         except Exception as exc:
             tb = traceback.format_exc()
-            print(
-                f"Unexpected error: {exc}\n"
-                f"Request details: method={request.method}, url={url}, headers={headers}, "
-                f"path={path}, query_params={dict(request.query_params)}\n"
-                f"Traceback:\n{tb}"
+            logger.error(
+                "Error forwarding GET request",
+                extra={
+                    "error": str(exc),
+                    "error_type": type(exc).__name__,
+                    "method": request.method,
+                    "url": url,
+                    "path": path,
+                    "query_params": dict(request.query_params),
+                    "traceback": tb,
+                },
             )
             return create_error_response(
                 "internal_error", "An unexpected server error occurred", 500

router/wallet.py

@@ -0,0 +1,190 @@
+import os
+from typing import Literal
+
+from cashu.core.base import Token
+from cashu.wallet.helpers import deserialize_token_from_string, receive, send
+from cashu.wallet.wallet import Wallet
+
+from .db import ApiKey, AsyncSession
+from .logging import get_logger
+
+# from .cashu import (
+#     credit_balance,
+#     delete_key_if_zero_balance,
+#     refund_balance,
+#     wallet,
+# )
+# from .cashu import (
+#     check_for_refunds,
+#     init_wallet,
+#     periodic_payout,
+# )
+
+logger = get_logger(__name__)
+
+CurrencyUnit = Literal["sat", "msat"]
+
+TRUSTED_MINTS = os.environ["CASHU_MINTS"].split(",")
+PRIMARY_MINT_URL = TRUSTED_MINTS[0]
+
+
+async def get_balance(unit: CurrencyUnit) -> int:
+    wallet = await Wallet.with_db(
+        PRIMARY_MINT_URL,
+        # DATABASE_URL,
+        db=".wallet",
+        load_all_keysets=True,
+        unit=unit,
+    )
+    await wallet.load_proofs()
+    return wallet.available_balance.amount
+
+
+async def recieve_token(
+    token: str,
+) -> tuple[int, CurrencyUnit, str]:  # amount, unit, mint_url
+    # trusted_mints = os.environ["CASHU_MINTS"].split(",")
+    token_obj = deserialize_token_from_string(token)
+    wallet = await Wallet.with_db(
+        token_obj.mint,
+        db=".wallet",
+        load_all_keysets=True,
+        unit=token_obj.unit,
+    )
+    if token_obj.mint in TRUSTED_MINTS and token_obj.mint != PRIMARY_MINT_URL:
+        return await swap_to_primary_mint(token_obj, wallet)
+    elif token_obj.mint not in TRUSTED_MINTS:
+        raise ValueError("Mint URL is not supported by this proxy")
+    await receive(wallet, token_obj)
+    return token_obj.amount, token_obj.unit, token_obj.mint
+
+
+async def send_token(
+    amount: int, unit: CurrencyUnit, mint_url: str | None = None
+) -> str:
+    wallet = await Wallet.with_db(
+        mint_url or PRIMARY_MINT_URL,
+        db=".wallet",
+        load_all_keysets=True,
+        unit=unit,
+    )
+    balance, token = await send(wallet, amount=amount, lock="", legacy=False)
+    return token
+
+
+async def swap_to_primary_mint(
+    token_obj: Token, wallet: Wallet
+) -> tuple[int, CurrencyUnit, str]:
+    print(f"swap_to_primary_mint, token_obj: {token_obj}")
+    if token_obj.unit == "sat":
+        amount_msat = token_obj.amount * 1000
+    elif token_obj.unit == "msat":
+        amount_msat = token_obj.amount
+    else:
+        raise ValueError("Invalid unit")
+    estimated_fee_sat = max(amount_msat // 1000 * 0.01, 2)
+    amount_msat_after_fee = amount_msat - estimated_fee_sat * 1000
+    mint_quote = await wallet.mint_quote(amount_msat_after_fee, "sat")
+    melt_quote = await wallet.melt_quote(mint_quote.request, amount_msat_after_fee)
+    _ = await wallet.melt(
+        proofs=token_obj.proofs,
+        invoice=mint_quote.request,
+        fee_reserve=melt_quote.fee_reserve,
+        quote_id=melt_quote.quote,
+    )
+
+    _ = await wallet.mint(token_obj.amount, mint_quote.quote)
+
+    return token_obj.amount, "sat", PRIMARY_MINT_URL
+
+
+# insert initial token state here to reduce db calls
+# async def create_refund_token(
+#     amount: int, unit: CurrencyUnit, mint_url: str | None = None
+# ) -> str:
+#     wallet = await Wallet.with_db(
+#         mint_url, DATABASE_URL, load_all_keysets=True, unit=unit
+#     )
+#     if wallet.balance_per_minturl(unit=unit)[mint_url] < amount:
+#         raise ValueError("Wallet has no balance")
+#     if mint_url is None:
+#         mint_url = wallet.mint_urls[0]
+#     return await wallet._make_token(amount, unit=unit, mint_url=mint_url)
+
+
+# async def redeem_token(token: str) -> Token:
+#     token_obj = deserialize_token_from_string(token)
+#     wallet = await Wallet.with_db(
+#         token_obj.mint,
+#         DATABASE_URL,
+#         load_all_keysets=True,
+#         unit=token_obj.unit,
+#     )
+#     return await redeem_universal(wallet, token_obj)
+
+
+async def credit_balance(cashu_token: str, key: ApiKey, session: AsyncSession) -> int:
+    amount, unit, mint_url = await recieve_token(cashu_token)
+    if unit == "sat":
+        amount = amount * 1000
+    if mint_url != PRIMARY_MINT_URL:
+        raise ValueError("Mint URL is not supported by this proxy")
+    key.balance += amount
+    session.add(key)
+    await session.commit()
+    logger.info(
+        "Cashu token successfully redeemed and stored",
+        extra={"amount": amount, "unit": unit, "mint_url": mint_url},
+    )
+    return amount
+
+
+async def send_to_lnurl(amount: int, unit: CurrencyUnit, lnurl: str) -> dict[str, int]:
+    raise NotImplementedError
+
+
+async def check_for_refunds() -> None:
+    print("check_for_refunds, temp not implemented")
+
+
+async def init_wallet() -> None:
+    balance = await get_balance("sat")
+    print(f"init_wallet, balance: {balance}")
+
+
+async def periodic_payout() -> None:
+    print("periodic_payout, temp not implemented")
+
+
+# class Proof:
+#     """
+#     Represents an ecash bill
+#     """
+
+
+# def redeem_to_proofs(self, token: str) -> list[Proof]:
+#     raise NotImplementedError
+
+
+# class Payment:
+#     """
+#     Stores all cashu payment related data
+#     """
+
+#     def __init__(self, token: str) -> None:
+#         self.initial_token = token
+#         amount, unit, mint_url = self.parse_token(token)
+#         self.amount = amount
+#         self.unit = unit
+#         self.mint_url = mint_url
+
+#         self.claimed_proofs = redeem_to_proofs(token)
+
+#     def parse_token(self, token: str) -> tuple[int, CurrencyUnit, str]:
+#         raise NotImplementedError
+
+#     def refund_full(self) -> None:
+#         raise NotImplementedError
+
+#     def refund_partial(self, amount: int) -> None:
+#         raise NotImplementedError

tests/conftest.py

@@ -1,7 +1,7 @@
 import asyncio
 import os
 from typing import AsyncGenerator, Generator
-from unittest.mock import AsyncMock, MagicMock, patch
+from unittest.mock import patch
 
 import pytest
 import pytest_asyncio
@@ -14,14 +14,14 @@ from sqlmodel.ext.asyncio.session import AsyncSession
 # Save original environment variables
 ORIGINAL_ENV = os.environ.copy()
 
-# Set test environment variables before importing the app
+# Set test environment variables BEFORE importing the app
 TEST_ENV = {
     "UPSTREAM_BASE_URL": "https://api.example.com",
     "UPSTREAM_API_KEY": "test-upstream-key",
     "NAME": "TestRoutstrNode",
     "DESCRIPTION": "Test Node",
     "NPUB": "npub1test",
-    "MINT": "https://test.mint.com",
+    "CASHU_MINTS": "https://test.mint.com",
     "HTTP_URL": "http://test.example.com",
     "ONION_URL": "http://test.onion",
     "CORS_ORIGINS": "*",
@@ -36,28 +36,9 @@ TEST_ENV = {
 # Apply test environment
 os.environ.update(TEST_ENV)
 
-# Mock the Wallet class from sixty_nuts before importing the app
-with patch("sixty_nuts.Wallet") as mock_wallet_class:
-    # Create a mock wallet instance
-    mock_wallet = AsyncMock()
-    mock_wallet.__aenter__ = AsyncMock(return_value=mock_wallet)
-    mock_wallet.__aexit__ = AsyncMock(return_value=None)
-
-    # Mock wallet state
-    mock_state = MagicMock()
-    mock_state.balance = 1000  # Balance in sats
-    mock_wallet.fetch_wallet_state = AsyncMock(return_value=mock_state)
-
-    # Mock other wallet methods
-    mock_wallet.send_to_lnurl = AsyncMock(return_value=100)
-    mock_wallet.redeem = AsyncMock(return_value=(1, "msat"))
-    mock_wallet.send = AsyncMock(return_value="cashu:token123")
-
-    # Make the Wallet class return our mock when instantiated
-    mock_wallet_class.return_value = mock_wallet
-
-    from router.db import get_session
-    from router.main import app
+# Now import modules that depend on environment variables
+from router.db import get_session  # noqa: E402
+from router.main import app  # noqa: E402
 
 
 @pytest.fixture(scope="session")
@@ -98,28 +79,9 @@ async def test_session(test_engine: AsyncEngine) -> AsyncGenerator[AsyncSession,
 def test_client() -> Generator[TestClient, None, None]:
     """Create a test client for the FastAPI app."""
     with patch.dict(os.environ, TEST_ENV, clear=True):
-        with patch("sixty_nuts.Wallet") as mock_wallet_class:
-            # Create a mock wallet instance
-            mock_wallet = AsyncMock()
-            mock_wallet.__aenter__ = AsyncMock(return_value=mock_wallet)
-            mock_wallet.__aexit__ = AsyncMock(return_value=None)
-
-            # Mock wallet state
-            mock_state = MagicMock()
-            mock_state.balance = 1000  # Balance in sats
-            mock_wallet.fetch_wallet_state = AsyncMock(return_value=mock_state)
-
-            # Mock other wallet methods
-            mock_wallet.send_to_lnurl = AsyncMock(return_value=100)
-            mock_wallet.redeem = AsyncMock(return_value=(1, "msat"))
-            mock_wallet.send = AsyncMock(return_value="cashu:token123")
-
-            # Make the Wallet class return our mock when instantiated
-            mock_wallet_class.return_value = mock_wallet
-
-            with patch("router.models.update_sats_pricing") as mock_update:
-                mock_update.return_value = None
-                yield TestClient(app)
+        with patch("router.models.update_sats_pricing") as mock_update:
+            mock_update.return_value = None
+            yield TestClient(app)
 
 
 @pytest_asyncio.fixture
@@ -133,32 +95,14 @@ async def async_client(test_session: AsyncSession) -> AsyncGenerator[AsyncClient
 
     # Mock startup tasks
     with patch.dict(os.environ, TEST_ENV, clear=True):
-        with patch("sixty_nuts.Wallet") as mock_wallet_class:
-            # Create a mock wallet instance
-            mock_wallet = AsyncMock()
-            mock_wallet.__aenter__ = AsyncMock(return_value=mock_wallet)
-            mock_wallet.__aexit__ = AsyncMock(return_value=None)
+        with patch("router.models.update_sats_pricing") as mock_update:
+            mock_update.return_value = None
 
-            # Mock wallet state
-            mock_state = MagicMock()
-            mock_state.balance = 1000  # Balance in sats
-            mock_wallet.fetch_wallet_state = AsyncMock(return_value=mock_state)
-
-            # Mock other wallet methods
-            mock_wallet.send_to_lnurl = AsyncMock(return_value=100)
-            mock_wallet.redeem = AsyncMock(return_value=(1, "msat"))
-            mock_wallet.send = AsyncMock(return_value="cashuAoken123")
-
-            # Make the Wallet class return our mock when instantiated
-            mock_wallet_class.return_value = mock_wallet
-
-            with patch("router.models.update_sats_pricing") as mock_update:
-                mock_update.return_value = None
-
-                async with AsyncClient(
-                    transport=ASGITransport(app=app), base_url="http://test"
-                ) as client:
-                    yield client
+            async with AsyncClient(
+                transport=ASGITransport(app=app),  # type: ignore
+                base_url="http://test",
+            ) as client:
+                yield client
 
     app.dependency_overrides.clear()
 

tests/test_proxy.py

@@ -1,353 +0,0 @@
-import json
-import os
-import uuid
-from typing import AsyncGenerator
-from unittest.mock import AsyncMock, patch
-
-import pytest
-import pytest_asyncio
-from httpx import AsyncClient
-
-from router.db import ApiKey, AsyncSession
-
-
-@pytest_asyncio.fixture
-async def api_key_with_balance(test_session: AsyncSession) -> ApiKey:
-    """Create an API key with sufficient balance."""
-    unique_id = str(uuid.uuid4())[:8]
-    key = ApiKey(
-        hashed_key=f"test-hashed-key-{unique_id}",
-        balance=10000000,  # 10,000 sats in msats
-        refund_address=None,
-        total_spent=0,
-        total_requests=0,
-    )
-    test_session.add(key)
-    await test_session.commit()
-    await test_session.refresh(key)
-    return key
-
-
-@pytest.mark.asyncio
-async def test_proxy_requires_authentication(async_client: AsyncClient) -> None:
-    """Test that proxy endpoints require authentication."""
-    response = await async_client.post("/v1/chat/completions")
-
-    assert response.status_code == 401
-    assert response.json()["detail"] == "Unauthorized"
-
-
-@pytest.mark.asyncio
-async def test_proxy_empty_bearer_token(async_client: AsyncClient) -> None:
-    """Test that proxy endpoints return structured error for empty bearer token."""
-    response = await async_client.post(
-        "/v1/chat/completions", headers={"Authorization": "Bearer "}
-    )
-
-    assert response.status_code == 401
-    assert (
-        "API key or Cashu token required"
-        in response.json()["detail"]["error"]["message"]
-    )
-
-
-@pytest.mark.asyncio
-async def test_proxy_with_insufficient_balance(
-    async_client: AsyncClient, test_session: AsyncSession
-) -> None:
-    """Test proxy request with insufficient balance."""
-    # Create key with minimal balance
-    unique_id = str(uuid.uuid4())[:8]
-    key = ApiKey(
-        hashed_key=f"low-balance-key-{unique_id}",
-        balance=100,  # Only 0.1 sats
-        refund_address=None,
-        total_spent=0,
-        total_requests=0,
-    )
-    test_session.add(key)
-    await test_session.commit()
-
-    # Mock the models.json check
-    with patch("os.path.exists", return_value=False):
-        response = await async_client.post(
-            "/v1/chat/completions",
-            headers={"Authorization": f"Bearer sk-{key.hashed_key}"},
-            json={"model": "gpt-4", "messages": [{"role": "user", "content": "Hello"}]},
-        )
-
-    assert response.status_code == 402
-    assert "Insufficient balance" in response.json()["detail"]["error"]["message"]
-
-
-@pytest.mark.asyncio
-async def test_proxy_invalid_json_body(
-    async_client: AsyncClient, api_key_with_balance: ApiKey
-) -> None:
-    """Test proxy request with invalid JSON body."""
-    response = await async_client.post(
-        "/v1/chat/completions",
-        headers={
-            "Authorization": f"Bearer sk-{api_key_with_balance.hashed_key}",
-            "Content-Type": "application/json",
-        },
-        content=b'{"invalid": json",}',  # Invalid JSON
-    )
-
-    assert response.status_code == 400
-    error_data = response.json()
-    assert error_data["error"]["type"] == "invalid_request_error"
-    assert error_data["error"]["code"] == "invalid_json"
-
-
-@pytest.mark.asyncio
-async def test_proxy_successful_request_mock(
-    async_client: AsyncClient, api_key_with_balance: ApiKey, test_session: AsyncSession
-) -> None:
-    """Test successful proxy request with mocked upstream."""
-    mock_response_data = {
-        "id": "chatcmpl-123",
-        "object": "chat.completion",
-        "created": 1677652288,
-        "model": "gpt-4",
-        "choices": [
-            {
-                "index": 0,
-                "message": {
-                    "role": "assistant",
-                    "content": "Hello! How can I help you?",
-                },
-                "finish_reason": "stop",
-            }
-        ],
-        "usage": {"prompt_tokens": 9, "completion_tokens": 10, "total_tokens": 19},
-    }
-
-    with patch("httpx.AsyncClient") as mock_client_class:
-        mock_client = AsyncMock()
-        mock_client_class.return_value = mock_client
-
-        # Create a mock response
-        mock_response = AsyncMock()
-        mock_response.status_code = 200
-        mock_response.headers = {"content-type": "application/json"}
-        mock_response.aread = AsyncMock(
-            return_value=json.dumps(mock_response_data).encode()
-        )
-        mock_response.aiter_bytes = AsyncMock()
-        mock_response.aclose = AsyncMock()
-
-        mock_client.send = AsyncMock(return_value=mock_response)
-        mock_client.build_request = AsyncMock()
-        mock_client.aclose = AsyncMock()
-
-        # Also mock the models.json check and pay_out
-        with patch("os.path.exists", return_value=False):
-            with patch("router.cashu.pay_out") as mock_payout:
-                mock_payout.return_value = None
-
-                response = await async_client.post(
-                    "/v1/chat/completions",
-                    headers={
-                        "Authorization": f"Bearer sk-{api_key_with_balance.hashed_key}"
-                    },
-                    json={
-                        "model": "gpt-4",
-                        "messages": [{"role": "user", "content": "Hello"}],
-                    },
-                )
-
-        assert response.status_code == 200
-        response_json = response.json()
-
-        # Verify the response includes the original data plus cost
-        assert response_json["id"] == "chatcmpl-123"
-        assert "cost" in response_json
-        assert response_json["cost"]["total_msats"] >= 0
-
-        # Verify balance was deducted
-        await test_session.refresh(api_key_with_balance)
-        assert api_key_with_balance.balance < 10000000
-        assert api_key_with_balance.total_requests == 1
-
-
-@pytest.mark.asyncio
-async def test_proxy_streaming_response(
-    async_client: AsyncClient, api_key_with_balance: ApiKey
-) -> None:
-    """Test proxy request with streaming response."""
-    # Mock SSE stream chunks
-    stream_chunks = [
-        b'data: {"id":"chatcmpl-123","object":"chat.completion.chunk","created":1677652288,"model":"gpt-4","choices":[{"delta":{"content":"Hello"},"index":0}]}\n\n',
-        b'data: {"id":"chatcmpl-123","object":"chat.completion.chunk","created":1677652288,"model":"gpt-4","choices":[{"delta":{"content":" there!"},"index":0}]}\n\n',
-        b'data: {"id":"chatcmpl-123","object":"chat.completion.chunk","created":1677652288,"model":"gpt-4","choices":[{"delta":{},"index":0,"finish_reason":"stop"}],"usage":{"prompt_tokens":9,"completion_tokens":3,"total_tokens":12}}\n\n',
-        b"data: [DONE]\n\n",
-    ]
-
-    async def mock_aiter_bytes() -> AsyncGenerator[bytes, None]:
-        for chunk in stream_chunks:
-            yield chunk
-
-    with patch("httpx.AsyncClient") as mock_client_class:
-        mock_client = AsyncMock()
-        mock_client_class.return_value = mock_client
-
-        mock_response = AsyncMock()
-        mock_response.status_code = 200
-        mock_response.headers = {"content-type": "text/event-stream"}
-        mock_response.aiter_bytes = lambda: mock_aiter_bytes()
-        mock_response.aclose = AsyncMock()
-
-        mock_client.send = AsyncMock(return_value=mock_response)
-        mock_client.build_request = AsyncMock()
-        mock_client.aclose = AsyncMock()
-
-        with patch("os.path.exists", return_value=False):
-            with patch("router.cashu.pay_out") as mock_payout:
-                mock_payout.return_value = None
-
-                response = await async_client.post(
-                    "/v1/chat/completions",
-                    headers={
-                        "Authorization": f"Bearer sk-{api_key_with_balance.hashed_key}"
-                    },
-                    json={
-                        "model": "gpt-4",
-                        "messages": [{"role": "user", "content": "Hello"}],
-                        "stream": True,
-                    },
-                )
-
-        assert response.status_code == 200
-        assert response.headers["content-type"] == "text/event-stream"
-
-
-@pytest.mark.asyncio
-async def test_proxy_handles_upstream_errors(
-    async_client: AsyncClient, api_key_with_balance: ApiKey
-) -> None:
-    """Test proxy handles upstream connection errors gracefully."""
-    with patch("httpx.AsyncClient") as mock_client_class:
-        mock_client = AsyncMock()
-        mock_client_class.return_value = mock_client
-
-        # Simulate connection error
-        mock_client.send.side_effect = Exception("Connection refused")
-        mock_client.build_request = AsyncMock()
-        mock_client.aclose = AsyncMock()
-
-        with patch("os.path.exists", return_value=False):
-            response = await async_client.post(
-                "/v1/chat/completions",
-                headers={
-                    "Authorization": f"Bearer sk-{api_key_with_balance.hashed_key}"
-                },
-                json={
-                    "model": "gpt-4",
-                    "messages": [{"role": "user", "content": "Hello"}],
-                },
-            )
-
-        assert response.status_code == 500
-        error_data = response.json()
-        assert error_data["error"]["type"] == "internal_error"
-        assert error_data["error"]["message"] == "An unexpected server error occurred"
-
-
-@pytest.mark.asyncio
-async def test_proxy_with_model_based_pricing(
-    async_client: AsyncClient, test_session: AsyncSession
-) -> None:
-    """Test proxy with model-based pricing enabled."""
-    # Create API key with sufficient balance
-    unique_id = str(uuid.uuid4())[:8]
-    key = ApiKey(
-        hashed_key=f"model-pricing-key-{unique_id}",
-        balance=10000000,  # 10,000 sats
-        refund_address=None,
-        total_spent=0,
-        total_requests=0,
-    )
-    test_session.add(key)
-    await test_session.commit()
-
-    with patch.dict(os.environ, {"MODEL_BASED_PRICING": "true"}):
-        with patch("os.path.exists", return_value=True):
-            # Mock a model with pricing
-            from router.models import MODELS, Architecture, Model, Pricing, TopProvider
-
-            test_model = Model(
-                id="gpt-4",
-                name="GPT-4",
-                created=1680000000,
-                description="Test model",
-                context_length=8192,
-                architecture=Architecture(
-                    modality="text",
-                    input_modalities=["text"],
-                    output_modalities=["text"],
-                    tokenizer="cl100k_base",
-                    instruct_type="none",
-                ),
-                pricing=Pricing(
-                    prompt=0.03,
-                    completion=0.06,
-                    request=0.001,
-                    image=0.0,
-                    web_search=0.0,
-                    internal_reasoning=0.0,
-                ),
-                sats_pricing=Pricing(
-                    prompt=300,  # 300 sats per 1k tokens
-                    completion=600,
-                    request=10,
-                    image=0.0,
-                    web_search=0.0,
-                    internal_reasoning=0.0,
-                    max_cost=5000,  # 5000 sats max
-                ),
-                top_provider=TopProvider(
-                    context_length=8192, max_completion_tokens=4096, is_moderated=False
-                ),
-            )
-
-            # Temporarily replace models
-            original_models = MODELS[:]
-            MODELS.clear()
-            MODELS.append(test_model)
-
-            # Mock the upstream HTTP client
-            with patch("httpx.AsyncClient") as mock_client_class:
-                mock_client = AsyncMock()
-                mock_client_class.return_value = mock_client
-
-                # Create a mock response
-                mock_response = AsyncMock()
-                mock_response.status_code = 200
-                mock_response.headers = {"content-type": "application/json"}
-                mock_response.aread = AsyncMock(
-                    return_value=b'{"id": "test", "model": "gpt-4"}'
-                )
-                mock_response.aiter_bytes = AsyncMock()
-                mock_response.aclose = AsyncMock()
-
-                mock_client.send = AsyncMock(return_value=mock_response)
-                mock_client.build_request = AsyncMock()
-                mock_client.aclose = AsyncMock()
-
-                try:
-                    response = await async_client.post(
-                        "/v1/chat/completions",
-                        headers={"Authorization": f"Bearer sk-{key.hashed_key}"},
-                        json={
-                            "model": "gpt-4",
-                            "messages": [{"role": "user", "content": "Hello"}],
-                        },
-                    )
-
-                    # Should succeed because balance (10,000 sats) > max_cost (5000 sats)
-                    assert response.status_code == 200
-
-                finally:
-                    MODELS.clear()
-                    MODELS.extend(original_models)