# Insert Menu Items - Comprehensive Logging Guide

## Overview

All logs are written to **both console and log file** (`logs/app.log`) in JSON format with structured data.

## Log Flow

### 1. Request Received (Sync - Returns immediately)

```json
{
  "event": "insert_menu_items_request",
  "request_id": "550e8400-e29b-41d4-a716-446655440000",
  "filename": "menu.jpg",
  "city": "sofia",
  "source_language": "bg",
  "target_language": "en"
}
```

```json
{
  "event": "VALIDATING_REQUEST",
  "request_id": "550e8400-e29b-41d4-a716-446655440000",
  "filename": "menu.jpg",
  "content_type": "image/jpeg"
}
```

```json
{
  "event": "FILE_READ_SUCCESS",
  "request_id": "550e8400-e29b-41d4-a716-446655440000",
  "filename": "menu.jpg",
  "size_bytes": 245678,
  "size_kb": 239.92
}
```

```json
{
  "event": "SCHEDULING_BACKGROUND_TASK",
  "request_id": "550e8400-e29b-41d4-a716-446655440000",
  "city": "sofia",
  "source_language": "bg",
  "target_language": "en"
}
```

```json
{
  "event": "REQUEST_ACCEPTED_202",
  "request_id": "550e8400-e29b-41d4-a716-446655440000",
  "city": "sofia",
  "filename": "menu.jpg",
  "background_task_scheduled": true
}
```

---

### 2. Background Processing Starts (Async)

```json
{
  "event": "menu_upload_processing_started",
  "request_id": "550e8400-e29b-41d4-a716-446655440000",
  "city": "sofia",
  "filename": "menu.jpg",
  "source_language": "bg",
  "target_language": "en"
}
```

---

### 3. Step 1: Menu Extraction

#### Step 1 Start
```json
{
  "event": "STEP_1_START: Calling menu extraction service",
  "request_id": "550e8400-e29b-41d4-a716-446655440000",
  "image_size_bytes": 245678,
  "mime_type": "image/jpeg"
}
```

#### Step 1 Success
```json
{
  "event": "STEP_1_COMPLETED: Menu extraction successful",
  "request_id": "550e8400-e29b-41d4-a716-446655440000",
  "categories_count": 5,
  "restaurant_name": "Restaurant Name",
  "model_used": "gpt-4o-mini"
}
```

#### Step 1 Failed (if error)
```json
{
  "level": "ERROR",
  "event": "STEP_1_FAILED: Menu extraction error",
  "request_id": "550e8400-e29b-41d4-a716-446655440000",
  "error": "Error message here",
  "error_type": "MenuExtractionException"
}
```

---

### 4. Step 2: Data Transformation (Adapter)

#### Step 2 Start
```json
{
  "event": "STEP_2_START: Transforming menu data using adapter",
  "request_id": "550e8400-e29b-41d4-a716-446655440000",
  "categories_to_transform": 5
}
```

#### Adapter Processing (Debug Level)
```json
{
  "event": "adapter_transform_started",
  "categories_count": 5,
  "city": "sofia"
}
```

```json
{
  "event": "adapter_transforming_category",
  "category_name": "Salads",
  "items_count": 8,
  "has_description": true
}
```

```json
{
  "event": "adapter_transforming_item",
  "item_name": "Caesar Salad",
  "original_price": "15.00 лв",
  "extracted_price": 15.0,
  "original_serving": "250g",
  "extracted_gramaj": 250
}
```

```json
{
  "event": "adapter_transform_completed",
  "categories_count": 5,
  "city": "sofia"
}
```

#### Step 2 Success
```json
{
  "event": "STEP_2_COMPLETED: Menu data transformation successful",
  "request_id": "550e8400-e29b-41d4-a716-446655440000",
  "categories_count": 5,
  "total_items": 23,
  "target_city": "sofia"
}
```

#### Step 2 Failed (if error)
```json
{
  "level": "ERROR",
  "event": "STEP_2_FAILED: Adapter transformation error",
  "request_id": "550e8400-e29b-41d4-a716-446655440000",
  "error": "Error message here",
  "error_type": "ValueError"
}
```

---

### 5. Step 3: External API Call

#### Step 3 Start
```json
{
  "event": "STEP_3_START: Calling external createMenu.php API",
  "request_id": "550e8400-e29b-41d4-a716-446655440000",
  "city": "sofia",
  "url": "https://zavedenia.com/apps/orderapprestaurant/api/createMenu.php",
  "categories_count": 5,
  "total_items": 23
}
```

#### API Request Attempt
```json
{
  "event": "API_REQUEST_ATTEMPT",
  "request_id": "550e8400-e29b-41d4-a716-446655440000",
  "attempt": 1,
  "max_retries": 3,
  "url": "https://zavedenia.com/apps/orderapprestaurant/api/createMenu.php",
  "payload_size": 3456,
  "categories_count": 5,
  "city": "sofia"
}
```

#### API Success
```json
{
  "event": "API_REQUEST_SUCCESS",
  "request_id": "550e8400-e29b-41d4-a716-446655440000",
  "attempt": 1,
  "status_code": 200,
  "response_length": 156,
  "response_preview": "{\"status\":\"success\",\"message\":\"Menu created\"}"
}
```

#### API HTTP Error (with retry)
```json
{
  "level": "ERROR",
  "event": "API_REQUEST_HTTP_ERROR",
  "request_id": "550e8400-e29b-41d4-a716-446655440000",
  "attempt": 1,
  "max_retries": 3,
  "status_code": 500,
  "error_message": "Internal Server Error",
  "url": "https://zavedenia.com/apps/orderapprestaurant/api/createMenu.php"
}
```

```json
{
  "level": "WARNING",
  "event": "API_REQUEST_RETRY_SCHEDULED",
  "request_id": "550e8400-e29b-41d4-a716-446655440000",
  "current_attempt": 1,
  "next_attempt": 2,
  "wait_seconds": 2
}
```

#### API Failed All Retries
```json
{
  "level": "ERROR",
  "event": "API_REQUEST_FAILED_ALL_RETRIES",
  "request_id": "550e8400-e29b-41d4-a716-446655440000",
  "total_attempts": 3,
  "final_status_code": 500
}
```

#### Step 3 Success
```json
{
  "event": "STEP_3_COMPLETED: External API call successful",
  "request_id": "550e8400-e29b-41d4-a716-446655440000",
  "city": "sofia"
}
```

#### Step 3 Failed (if error)
```json
{
  "level": "ERROR",
  "event": "STEP_3_FAILED: External API call error",
  "request_id": "550e8400-e29b-41d4-a716-446655440000",
  "error": "Error message here",
  "error_type": "ExternalServiceException"
}
```

---

### 6. Final Status

#### SUCCESS
```
========================================
```
```json
{
  "event": "MENU_UPLOAD_PROCESSING_COMPLETED_SUCCESSFULLY",
  "request_id": "550e8400-e29b-41d4-a716-446655440000",
  "city": "sofia",
  "filename": "menu.jpg",
  "source_language": "bg",
  "target_language": "en",
  "categories_count": 5,
  "total_items": 23,
  "processing_time_seconds": 12.45,
  "status": "SUCCESS"
}
```
```
========================================
```

#### FAILED
```
========================================
```
```json
{
  "level": "ERROR",
  "event": "MENU_UPLOAD_PROCESSING_FAILED",
  "request_id": "550e8400-e29b-41d4-a716-446655440000",
  "city": "sofia",
  "filename": "menu.jpg",
  "error_stage": "menu_extraction",
  "error": "Menu extraction failed: ...",
  "processing_time_seconds": 8.32,
  "status": "FAILED"
}
```
```
========================================
```

---

## Validation Errors (Immediate Response)

### Invalid File Type
```json
{
  "level": "ERROR",
  "event": "VALIDATION_FAILED",
  "request_id": "550e8400-e29b-41d4-a716-446655440000",
  "reason": "invalid_content_type",
  "content_type": "application/pdf"
}
```

### Empty File
```json
{
  "level": "ERROR",
  "event": "VALIDATION_FAILED",
  "request_id": "550e8400-e29b-41d4-a716-446655440000",
  "reason": "empty_file",
  "filename": "menu.jpg"
}
```

---

## Log Levels

- **INFO**: Normal flow events (steps, progress)
- **WARNING**: Retries, non-critical issues
- **ERROR**: Failures, exceptions
- **DEBUG**: Detailed processing (adapter item transformations)

## Log Files

- **Console**: Real-time streaming output (STDOUT)
- **File**: `logs/app.log` (rotating, max 10MB per file, 5 backups)

## Filtering Logs

### View only insert_menu_items logs:
```bash
tail -f logs/app.log | grep "request_id"
```

### View specific request:
```bash
grep "550e8400-e29b-41d4-a716-446655440000" logs/app.log
```

### View only final status:
```bash
grep "MENU_UPLOAD_PROCESSING_COMPLETED" logs/app.log
```

### View only errors:
```bash
grep "ERROR" logs/app.log | grep "insert_menu_items"
```

### View step-by-step progress:
```bash
grep -E "STEP_[0-9]_(START|COMPLETED|FAILED)" logs/app.log
```

## Enable Debug Logging

Set in `.env`:
```bash
LOG_LEVEL=DEBUG
```

This will show all adapter item-by-item transformations with price and gramaj extraction details.