feat: Add comprehensive logging to subscription matrix for debugging

This commit is contained in:
Christian 2026-01-27 01:46:38 +01:00
parent 1845c9aea2
commit 4ce8031513

View File

@ -153,9 +153,11 @@ class SubscriptionMatrixService:
try: try:
# Fill in data from invoices, but only for months within range # Fill in data from invoices, but only for months within range
logger.info(f"🔍 [MATRIX] Processing {len(invoices)} invoices") logger.info(f"🔍 [MATRIX] Processing {len(invoices)} invoices")
invoice_count = 0
for invoice in invoices: for invoice in invoices:
invoice_count += 1
invoice_number = invoice.get('bookedInvoiceNumber') or invoice.get('draftInvoiceNumber') invoice_number = invoice.get('bookedInvoiceNumber') or invoice.get('draftInvoiceNumber')
logger.debug(f"🔍 [MATRIX] Processing invoice {invoice_number}") logger.info(f"📄 [MATRIX] [{invoice_count}/{len(invoices)}] Processing invoice {invoice_number}")
# Determine status based on invoice type/endpoint it came from # Determine status based on invoice type/endpoint it came from
# Priority: use 'status' field, fallback to inferring from presence of certain fields # Priority: use 'status' field, fallback to inferring from presence of certain fields
invoice_status = invoice.get('status', 'unknown') invoice_status = invoice.get('status', 'unknown')
@ -189,11 +191,14 @@ class SubscriptionMatrixService:
# Process invoice lines # Process invoice lines
lines = invoice.get('lines', []) lines = invoice.get('lines', [])
logger.debug(f"🔍 [MATRIX] Invoice {invoice_number} has {len(lines)} lines") logger.info(f"📋 [MATRIX] Invoice {invoice_number} has {len(lines)} lines")
line_num = 0
for line in lines: for line in lines:
line_num += 1
product_number = line.get('product', {}).get('productNumber') product_number = line.get('product', {}).get('productNumber')
product_name = line.get('product', {}).get('name') or line.get('description') product_name = line.get('product', {}).get('name') or line.get('description')
line_description = (line.get('description') or product_name or "").lower() line_description = (line.get('description') or product_name or "").lower()
logger.info(f" 📦 [MATRIX] Line {line_num}: Product='{product_name}', Number={product_number}")
# Check for period data # Check for period data
line_period_data = line.get('period', {}) line_period_data = line.get('period', {})
@ -210,13 +215,13 @@ class SubscriptionMatrixService:
skip_keywords = ['installation', 'opsætning', 'setup', 'hardware', 'engangs'] skip_keywords = ['installation', 'opsætning', 'setup', 'hardware', 'engangs']
should_skip = any(keyword in line_description for keyword in skip_keywords) should_skip = any(keyword in line_description for keyword in skip_keywords)
logger.info(f" 🔍 Checks: periode={has_periode_keyword}, abon={has_abonnement_keyword}, has_period={has_period}, should_skip={should_skip}")
if should_skip: if should_skip:
logger.debug(f"🔍 [MATRIX] Skipping one-time item: {product_name[:50] if product_name else 'NO NAME'}") logger.info(f" ❌ SKIPPED (one-time): {product_name[:60] if product_name else 'NO NAME'}")
continue continue
# Include if it has subscription indicators OR has period data OR just include everything logger.info(f" ✅ INCLUDED: {product_name[:60] if product_name else 'NO NAME'}")
# We'll filter later based on products appearing in multiple months
logger.debug(f"🔍 [MATRIX] Including: {product_name[:50] if product_name else 'NO NAME'} (periode={has_periode_keyword}, abon={has_abonnement_keyword}, period={has_period})")
if not product_number and not product_name: if not product_number and not product_name:
logger.debug(f"Skipping line without product number: {line}") logger.debug(f"Skipping line without product number: {line}")
@ -271,10 +276,15 @@ class SubscriptionMatrixService:
qty = float(line.get('quantity', 1)) qty = float(line.get('quantity', 1))
amount = unit_price * qty amount = unit_price * qty
logger.info(f" 💰 Amount: {amount} kr, Period: {period_from_str} to {period_to_str}")
# Determine month key (use first month if multi-month) # Determine month key (use first month if multi-month)
year_month = period_from.strftime('%Y-%m') year_month = period_from.strftime('%Y-%m')
logger.info(f" 📅 Month: {year_month}")
if year_month not in all_months: if year_month not in all_months:
# Skip lines outside the displayed month range # Skip lines outside the displayed month range
logger.info(f" ⏭️ SKIPPED: Month {year_month} outside display range {all_months[0]} - {all_months[-1]}")
continue continue
# Calculate period label # Calculate period label
@ -294,18 +304,21 @@ class SubscriptionMatrixService:
# Update cell # Update cell
cell = product_matrix[product_key][year_month] cell = product_matrix[product_key][year_month]
old_amount = cell["amount"]
cell["amount"] += amount cell["amount"] += amount
cell["status"] = self._merge_status(cell["status"], self._determine_status(invoice_status)) cell["status"] = self._merge_status(cell["status"], self._determine_status(invoice_status))
cell["invoice_number"] = invoice_number cell["invoice_number"] = invoice_number
cell["period_from"] = period_from.isoformat().split('T')[0] cell["period_from"] = period_from.isoformat().split('T')[0]
cell["period_to"] = period_to.isoformat().split('T')[0] cell["period_to"] = period_to.isoformat().split('T')[0]
cell["period_label"] = period_label cell["period_label"] = period_label
logger.info(f" ✏️ Updated {product_key} @ {year_month}: {old_amount} kr -> {cell['amount']} kr, status={cell['status']}")
except Exception as e: except Exception as e:
logger.error(f"❌ Error aggregating data: {e}") logger.error(f"❌ Error aggregating data: {e}")
# Filter out products that only appear in one month (one-time purchases, not subscriptions) # Filter out products that only appear in one month (one-time purchases, not subscriptions)
# Keep products that appear in 2+ months OR have subscription keywords # Keep products that appear in 2+ months OR have subscription keywords
logger.info(f"\n🔍 [MATRIX] Filtering products. Total collected: {len(product_matrix)}")
filtered_matrix = {} filtered_matrix = {}
for product_key, months_data in product_matrix.items(): for product_key, months_data in product_matrix.items():
# Count how many months have actual data (not missing status) # Count how many months have actual data (not missing status)
@ -321,13 +334,16 @@ class SubscriptionMatrixService:
# Include if it appears in multiple months OR has subscription keywords # Include if it appears in multiple months OR has subscription keywords
if months_with_data >= 2 or has_subscription_indicators: if months_with_data >= 2 or has_subscription_indicators:
filtered_matrix[product_key] = months_data filtered_matrix[product_key] = months_data
logger.debug(f"✅ Including product: {product_name} (appears in {months_with_data} months, subscription_indicators={has_subscription_indicators})") logger.info(f" ✅ KEEP: '{product_name}' (months={months_with_data}, subscription_keyword={has_subscription_indicators})")
else: else:
logger.debug(f"❌ Filtering out: {product_name} (only in {months_with_data} month, no subscription indicators)") logger.info(f" ❌ REMOVE: '{product_name}' (months={months_with_data}, subscription_keyword={has_subscription_indicators})")
# Convert to output format # Convert to output format
logger.info(f"\n📊 [MATRIX] Final output: {len(filtered_matrix)} products after filtering")
products = [] products = []
for product_number, months_data in sorted(filtered_matrix.items()): for product_number, months_data in sorted(filtered_matrix.items()):
product_name = product_names.get(product_number, f"Product {product_number}")
logger.info(f" 📦 Building output for: {product_name}")
rows = [] rows = []
total_amount: float = 0.0 total_amount: float = 0.0
total_paid: float = 0.0 total_paid: float = 0.0