From 4ce80315137815776975fac7b4eda4bcd3b164b4 Mon Sep 17 00:00:00 2001 From: Christian Date: Tue, 27 Jan 2026 01:46:38 +0100 Subject: [PATCH] feat: Add comprehensive logging to subscription matrix for debugging --- app/services/subscription_matrix.py | 32 +++++++++++++++++++++-------- 1 file changed, 24 insertions(+), 8 deletions(-) diff --git a/app/services/subscription_matrix.py b/app/services/subscription_matrix.py index 82a6a21..9909660 100644 --- a/app/services/subscription_matrix.py +++ b/app/services/subscription_matrix.py @@ -153,9 +153,11 @@ class SubscriptionMatrixService: try: # Fill in data from invoices, but only for months within range logger.info(f"πŸ” [MATRIX] Processing {len(invoices)} invoices") + invoice_count = 0 for invoice in invoices: + invoice_count += 1 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 # Priority: use 'status' field, fallback to inferring from presence of certain fields invoice_status = invoice.get('status', 'unknown') @@ -189,11 +191,14 @@ class SubscriptionMatrixService: # Process invoice 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: + line_num += 1 product_number = line.get('product', {}).get('productNumber') product_name = line.get('product', {}).get('name') or line.get('description') 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 line_period_data = line.get('period', {}) @@ -210,13 +215,13 @@ class SubscriptionMatrixService: skip_keywords = ['installation', 'opsΓ¦tning', 'setup', 'hardware', 'engangs'] 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: - 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 - # Include if it has subscription indicators OR has period data OR just include everything - # 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})") + logger.info(f" βœ… INCLUDED: {product_name[:60] if product_name else 'NO NAME'}") if not product_number and not product_name: logger.debug(f"Skipping line without product number: {line}") @@ -271,10 +276,15 @@ class SubscriptionMatrixService: qty = float(line.get('quantity', 1)) 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) year_month = period_from.strftime('%Y-%m') + logger.info(f" πŸ“… Month: {year_month}") + if year_month not in all_months: # Skip lines outside the displayed month range + logger.info(f" ⏭️ SKIPPED: Month {year_month} outside display range {all_months[0]} - {all_months[-1]}") continue # Calculate period label @@ -294,18 +304,21 @@ class SubscriptionMatrixService: # Update cell cell = product_matrix[product_key][year_month] + old_amount = cell["amount"] cell["amount"] += amount cell["status"] = self._merge_status(cell["status"], self._determine_status(invoice_status)) cell["invoice_number"] = invoice_number cell["period_from"] = period_from.isoformat().split('T')[0] cell["period_to"] = period_to.isoformat().split('T')[0] 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: logger.error(f"❌ Error aggregating data: {e}") # 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 + logger.info(f"\nπŸ” [MATRIX] Filtering products. Total collected: {len(product_matrix)}") filtered_matrix = {} for product_key, months_data in product_matrix.items(): # 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 if months_with_data >= 2 or has_subscription_indicators: 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: - 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 + logger.info(f"\nπŸ“Š [MATRIX] Final output: {len(filtered_matrix)} products after filtering") products = [] 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 = [] total_amount: float = 0.0 total_paid: float = 0.0