import time from logging import getLogger from threading import Thread from uuid import uuid4 from fastapi import HTTPException, APIRouter, Depends from fastapi.responses import JSONResponse from fudo import fudo from models.sales import ItemWeb, OrderWeb from models.items import Item, Order from models.user import User from services.fudo_service import add_product_to_fudo from services.email_service import get_email_sender from services.logging_service import log_order, structured_logger, LogLevel import services.print_service as ps from services.data_service import DataServiceFactory from config.mails import PRINTER_DISCONNECTED_MAIL from config.messages import ErrorResponse, SuccessResponse, UserResponse from config.settings import DEVELOPMENT from auth.security import get_current_user logger = getLogger(__name__) # Data services initialization user_data_service = DataServiceFactory.get_user_service() product_data_service = DataServiceFactory.get_product_service() sale_data_service = DataServiceFactory.get_sales_service() # Global variables printer_orders = [] order_router = APIRouter() name_promo = "Shop" @order_router.post("/send") async def printer_order(order: OrderWeb, current_user: User = Depends(get_current_user)): """Process printer order""" logger.info(f"Printer order received from user {current_user.email} for table {order.table}") structured_logger.log_order_event( f"Print order received for table {order.table}", LogLevel.INFO, { "table": order.table, "items_count": len(order.items), "customer_id": order.customerId, "total_amount": order.totalAmount, "order_date": order.orderDate }, user_id=current_user.id, user_email=current_user.email ) # Printer status validation if not DEVELOPMENT: try: printer_status = ps.get_status() if not printer_status: logger.error(f"Printer is not connected. Order from user {current_user.email} cannot be processed.") structured_logger.log_print_event( f"Order rejected due to printer disconnection", LogLevel.ERROR, { "table": order.table, "user_id": current_user.id, "user_email": current_user.email, "items_count": len(order.items) }, user_id=current_user.id, user_email=current_user.email ) # Send notification email to admins email_thread = Thread( target=get_email_sender().send_email, args=( PRINTER_DISCONNECTED_MAIL["subject"], PRINTER_DISCONNECTED_MAIL["body"], ["erwinjacimino2003@gmail.com", "mompyn@gmail.com"] ), daemon=True ) email_thread.start() structured_logger.log_email_event( "Printer disconnection notification sent to admins", LogLevel.WARNING, { "trigger_user": current_user.email, "admin_emails": ["erwinjacimino2003@gmail.com", "mompyn@gmail.com"] }, user_id=current_user.id, user_email=current_user.email ) return JSONResponse(status_code=424, content={"message": ErrorResponse.PRINTER_DISCONNECTED}) except Exception as e: logger.error(f"Error checking printer status: {e}") structured_logger.log_print_event( "Printer status check failed", LogLevel.ERROR, { "error": str(e), "error_type": type(e).__name__, "user_id": current_user.id }, user_id=current_user.id, user_email=current_user.email ) return JSONResponse(status_code=500, content={"message": "Error interno del servidor"}) # Extract order data items = order.items table = order.table # Input validation if not items or not table: logger.warning(f"Invalid order data from user {current_user.email}: missing items or table") structured_logger.log_order_event( "Order validation failed: missing items or table", LogLevel.WARNING, { "has_items": bool(items), "table": table, "items_count": len(items) if items else 0 }, user_id=current_user.id, user_email=current_user.email ) return JSONResponse(status_code=400, content={"message": ErrorResponse.MISSING_FIELDS}) if not isinstance(table, int): logger.warning(f"Invalid table type from user {current_user.email}: {type(table)}") structured_logger.log_order_event( "Order validation failed: invalid table type", LogLevel.WARNING, { "table": table, "table_type": str(type(table)) }, user_id=current_user.id, user_email=current_user.email ) return JSONResponse(status_code=400, content={"message": ErrorResponse.INVALID_TABLE_TYPE}) logger.info(f"Processing order for table {table} with {len(items)} items") structured_logger.log_order_event( f"Starting order processing for table {table}", LogLevel.INFO, { "table": table, "items_count": len(items), "item_ids": [item.id for item in items], "item_quantities": [item.quantity for item in items] }, user_id=current_user.id, user_email=current_user.email ) # Add products to Fudo product_errors = [] # Get products data try: products = product_data_service.get_products([item.id for item in items]) logger.info(f"Retrieved {len(products)} products from database") structured_logger.log_order_event( f"Retrieved products for order processing", LogLevel.INFO, { "table": table, "requested_products": len(items), "found_products": len(products), "product_ids": [p.id for p in products] }, user_id=current_user.id, user_email=current_user.email ) except Exception as e: error_msg = f"Error retrieving products: {e}" logger.error(error_msg) structured_logger.log_database_event( "Failed to retrieve products for order", LogLevel.ERROR, { "table": table, "requested_product_ids": [item.id for item in items], "error": str(e), "error_type": type(e).__name__ }, user_id=current_user.id, user_email=current_user.email ) return JSONResponse(status_code=500, content={"message": "Error interno del servidor"}) beers_for_promo = 0 try: fudo.get_token() logger.info("Fudo token obtained successfully") for item, product in zip(items, products): try: # Si es dia de promo if time.localtime().tm_wday + 1 == product.promo_day and product.promo_id: logger.info(f"Applying promotion for product {product.id} on table {table}") fudo_product = add_product_to_fudo(product.promo_id, item.quantity, table) structured_logger.log_order_event( f"Promotion applied for product {product.name}", LogLevel.INFO, { "product_id": product.id, "promo_id": product.promo_id, "table": table, "quantity": item.quantity, "promo_day": product.promo_day, "current_day": time.localtime().tm_wday + 1 }, user_id=current_user.id, user_email=current_user.email ) #en caso contrario else: if product.type == name_promo: beers_for_promo += item.quantity logger.debug(f"Added {item.quantity} beers for promotion calculation") fudo_product = add_product_to_fudo(item.id, item.quantity, table) structured_logger.log_order_event( f"Added product {product.name} to Fudo", LogLevel.INFO, { "product_id": item.id, "product_name": product.name, "product_type": product.type, "table": table, "quantity": item.quantity, "is_beer": product.type == name_promo }, user_id=current_user.id, user_email=current_user.email ) if not fudo_product: error_msg = f"Error adding product {item.id} to table {table}." product_errors.append(error_msg) logger.error(error_msg) structured_logger.log_order_event( f"Failed to add product to Fudo", LogLevel.ERROR, { "product_id": item.id, "table": table, "quantity": item.quantity }, user_id=current_user.id, user_email=current_user.email ) except Exception as e: error_msg = f"Error processing product {item.id}: {e}" logger.error(error_msg) product_errors.append(error_msg) structured_logger.log_order_event( f"Error processing product {item.id}", LogLevel.ERROR, { "product_id": item.id, "table": table, "error": str(e), "error_type": type(e).__name__ }, user_id=current_user.id, user_email=current_user.email ) except Exception as e: error_msg = f"Error with Fudo integration: {e}" logger.error(error_msg) structured_logger.log_order_event( "Fudo integration error", LogLevel.ERROR, { "table": table, "error": str(e), "error_type": type(e).__name__ }, user_id=current_user.id, user_email=current_user.email ) return JSONResponse(status_code=500, content={"message": "Error interno del servidor"}) if product_errors: logger.error(f"Product errors occurred: {product_errors}") structured_logger.log_order_event( "Order processing failed due to product errors", LogLevel.ERROR, { "table": table, "product_errors": product_errors, "error_count": len(product_errors) }, user_id=current_user.id, user_email=current_user.email ) return JSONResponse( status_code=424, content={"message": ErrorResponse.PRODUCT_ADD_ERROR, "errors": product_errors} ) # User validation try: user = user_data_service.get_by_id(order.customerId) if not user: logger.warning(f"User not found: {order.customerId}") structured_logger.log_user_event( f"Order rejected: user not found", LogLevel.WARNING, { "requested_user_id": order.customerId, "table": table }, user_id=current_user.id, user_email=current_user.email ) return JSONResponse(status_code=404, content={"message": UserResponse.USER_NOT_FOUND.format(user_id=order.customerId)}) logger.info(f"Order customer validated: {user.email}") structured_logger.log_user_event( f"Order customer validated", LogLevel.INFO, { "customer_id": user.id, "customer_email": user.email, "customer_name": user.name, "table": table }, user_id=current_user.id, user_email=current_user.email ) except Exception as e: error_msg = f"Error validating user {order.customerId}: {e}" logger.error(error_msg) structured_logger.log_database_event( "User validation error during order processing", LogLevel.ERROR, { "requested_user_id": order.customerId, "table": table, "error": str(e), "error_type": type(e).__name__ }, user_id=current_user.id, user_email=current_user.email ) return JSONResponse(status_code=500, content={"message": "Error interno del servidor"}) # Get active sale try: active_sale_id = fudo.get_active_sale(fudo.get_table(table)) if not active_sale_id: error_msg = f"No active sale found for table {table}" logger.error(error_msg) structured_logger.log_order_event( "Order failed: no active sale found", LogLevel.ERROR, { "table": table, "customer_id": order.customerId }, user_id=current_user.id, user_email=current_user.email ) raise HTTPException(status_code=404, detail=error_msg) active_sale_id = active_sale_id['id'] logger.info(f"Active sale found for table {table}: {active_sale_id}") structured_logger.log_order_event( f"Active sale retrieved for table {table}", LogLevel.INFO, { "table": table, "sale_id": active_sale_id }, user_id=current_user.id, user_email=current_user.email ) except HTTPException: raise except Exception as e: error_msg = f"Error retrieving active sale for table {table}: {e}" logger.error(error_msg) structured_logger.log_order_event( "Error retrieving active sale", LogLevel.ERROR, { "table": table, "error": str(e), "error_type": type(e).__name__ }, user_id=current_user.id, user_email=current_user.email ) raise HTTPException(status_code=500, detail="Error interno del servidor") # Update user reward progress try: new_progress = user.reward_progress + beers_for_promo * 10 user_data_service.set_reward_progress(user.id, new_progress) logger.info(f"Updated reward progress for user {user.email}: {user.reward_progress} -> {new_progress}") structured_logger.log_user_event( f"Reward progress updated", LogLevel.INFO, { "user_id": user.id, "old_progress": user.reward_progress, "new_progress": new_progress, "beers_count": beers_for_promo, "points_added": beers_for_promo * 10, "table": table }, user_id=user.id, user_email=user.email ) except Exception as e: error_msg = f"Error updating reward progress for user {user.id}: {e}" logger.error(error_msg) structured_logger.log_database_event( "Failed to update reward progress", LogLevel.ERROR, { "user_id": user.id, "beers_for_promo": beers_for_promo, "error": str(e), "error_type": type(e).__name__ }, user_id=user.id, user_email=user.email ) # Don't fail the order for this, just log it new_progress = user.reward_progress # Create sale record try: sale = sale_data_service.create( order.customerId, active_sale_id or uuid4().hex, order.totalAmount, order.table, [item.id for item in items], [item.quantity for item in items] ) if sale > 0: logger.info(f"Sale created successfully: ID {sale}") structured_logger.log_order_event( f"Sale record created successfully", LogLevel.INFO, { "sale_id": sale, "customer_id": order.customerId, "table": table, "total_amount": order.totalAmount, "fudo_sale_id": active_sale_id, "items_count": len(items) }, user_id=current_user.id, user_email=current_user.email ) else: error_msg = "Failed to create sale record" logger.error(error_msg) structured_logger.log_database_event( "Sale creation failed", LogLevel.ERROR, { "customer_id": order.customerId, "table": table, "total_amount": order.totalAmount, "fudo_sale_id": active_sale_id }, user_id=current_user.id, user_email=current_user.email ) return JSONResponse(status_code=500, content={"message": "Error interno del servidor"}) except Exception as e: error_msg = f"Error creating sale record: {e}" logger.error(error_msg) structured_logger.log_database_event( "Sale creation error", LogLevel.ERROR, { "customer_id": order.customerId, "table": table, "error": str(e), "error_type": type(e).__name__ }, user_id=current_user.id, user_email=current_user.email ) return JSONResponse(status_code=500, content={"message": "Error interno del servidor"}) # Print order try: order_for_print = Order( table=table, items=[Item(name=product.name, price=product.price or 0, quantity=item.quantity) for product, item in zip(products, items)], customerName=user.name, totalAmount=order.totalAmount, orderDate=order.orderDate ) ps.print_order(order_for_print) logger.info(f"Order printed successfully for table {table}") structured_logger.log_print_event( f"Order printed successfully for table {table}", LogLevel.INFO, { "table": table, "customer_name": user.name, "total_amount": order.totalAmount, "items_count": len(items), "sale_id": sale }, user_id=current_user.id, user_email=current_user.email ) except Exception as e: error_msg = f"Error printing order for table {table}: {e}" logger.error(error_msg) structured_logger.log_print_event( f"Order print failed for table {table}", LogLevel.ERROR, { "table": table, "customer_name": user.name, "error": str(e), "error_type": type(e).__name__, "sale_id": sale }, user_id=current_user.id, user_email=current_user.email ) # Don't fail the order for print issues, just log it # Log order (legacy function) try: log_order(user.name, order.table, order_date=order.orderDate, items=[product.name for product in products]) structured_logger.log_order_event( f"Order completed successfully for table {table}", LogLevel.INFO, { "table": table, "customer_id": user.id, "customer_name": user.name, "customer_email": user.email, "total_amount": order.totalAmount, "items": [{"name": product.name, "quantity": item.quantity, "price": product.price} for product, item in zip(products, items)], "sale_id": sale, "new_reward_progress": new_progress, "beers_for_promo": beers_for_promo }, user_id=user.id, user_email=user.email ) except Exception as e: logger.error(f"Error in legacy order logging: {e}") # Don't fail the order for logging issues logger.info(f"Order processing completed successfully for table {table}, sale ID: {sale}") return JSONResponse({"message": SuccessResponse.ORDER_SUCCESS, "new_progress": new_progress})