# Atlas Record Cleaner Report - Debug Logging Guide

## Overview

Comprehensive debug logging has been added to the Atlas Record Cleaner Report application to help track what's happening during report generation, especially when making calls to external services (NBN Atlas API and BRC Record Cleaner API).

## What Gets Logged

### 1. Views (`views.py`)
- Form page loads and dataset fetching
- Report generation workflow (steps 1-9)
- Input validation
- CSV download requests
- Errors with full stack traces

### 2. Atlas Service (`services/atlas_service.py`)
- Data resource fetching from Atlas Registry
- Occurrence record fetching with pagination details
- API request URLs and response status codes
- Number of records per page and total counts

### 3. Record Cleaner Service (`services/record_cleaner_service.py`)
- Authentication token requests
- Validation API calls with pass/warn/fail counts
- Verification API calls with pass/warn/fail counts
- Processing times for verification
- Full workflow tracking for validate_and_verify

## Log Levels

- **DEBUG**: Detailed information for troubleshooting (API URLs, request/response details, step-by-step progress)
- **INFO**: General informational messages (successful operations, counts, summaries)
- **WARNING**: Warning messages (no data found, missing required data)
- **ERROR**: Error messages with full exception details and stack traces

## Where Logs Are Written

Logs are written to **two locations**:

### 1. Console Output
All logs are written to the console (stdout) when running the Django development server. You'll see them in your terminal.

Example:
```bash
python manage.py runserver
```

### 2. Log File
All logs are also written to `debug.log` in the project root directory:
```
/Users/hmj/Documents/code/devs-gone-wild-app/debug.log
```

The log file:
- Uses rotating file handler (max 10 MB per file)
- Keeps up to 5 backup files
- Is automatically excluded from git (via `.gitignore`)

## Log Format

Each log entry includes:
```
[LEVEL] YYYY-MM-DD HH:MM:SS logger_name module.function: message
```

Example:
```
[INFO] 2025-10-19 14:23:45 atlas_record_cleaner_report.views generate_report: STEP 1: Fetching occurrences from Atlas API
[DEBUG] 2025-10-19 14:23:45 atlas_record_cleaner_report.services.atlas_service fetch_atlas_occurrences: Request URL: https://records-ws.nbnatlas.org/occurrences/search?...
[INFO] 2025-10-19 14:23:46 atlas_record_cleaner_report.services.atlas_service fetch_atlas_occurrences: Page 1: Received 10 records (total available: 25)
```

## Viewing Logs

### Real-time Console Logs
Just run your Django server and watch the terminal:
```bash
python manage.py runserver
```

### Log File
View the log file in real-time:
```bash
tail -f debug.log
```

Or view the entire log file:
```bash
less debug.log
# or
cat debug.log
```

### Filtering Logs
Filter for specific levels or modules:
```bash
# Show only ERROR logs
grep "\[ERROR\]" debug.log

# Show only Record Cleaner API logs
grep "record_cleaner_service" debug.log

# Show only Atlas API logs
grep "atlas_service" debug.log

# Show validation/verification workflow
grep -A 5 -B 5 "validate_and_verify" debug.log
```

## Example Log Flow

When generating a report, you'll see logs like:

```
[INFO] ================================================================================
[INFO] Starting Record Cleaner report generation
[INFO] ================================================================================
[DEBUG] Input type: dataset
[DEBUG] Data resource UID: dr123
[INFO] STEP 1: Fetching occurrences from Atlas API
[DEBUG] Fetching by dataset UID: dr123 (page_size=10, max_records=None)
[INFO] Starting fetch of Atlas occurrences (page_size=10, max_records=None)
[DEBUG] Fetching page 1 from Atlas API
[DEBUG] Request URL: https://records-ws.nbnatlas.org/occurrences/search?...
[DEBUG] Atlas API response status: 200
[INFO] Page 1: Received 10 records (total available: 25)
[INFO] Atlas fetch complete: Retrieved 10 total occurrences across 1 page(s)
[INFO] Successfully fetched 10 occurrences from Atlas
[INFO] STEP 2: Mapping occurrences to Record Cleaner format
[DEBUG] Mapped 10 records to Record Cleaner format
[INFO] STEP 3: Initializing Record Cleaner client
[DEBUG] Record Cleaner client initialized
[INFO] STEP 4: Validating and verifying 10 records via Record Cleaner API
[INFO] ============================================================
[INFO] Starting validate_and_verify workflow
[INFO] ============================================================
[INFO] Phase 1: Validation
[INFO] Validating 10 records via Record Cleaner API
[DEBUG] Token endpoint: https://record-cleaner.brc.ac.uk/token
[INFO] Requesting new authentication token from Record Cleaner API
[DEBUG] Token API response status: 200
[INFO] Successfully obtained Record Cleaner token (expires at 2025-10-19 14:38:45)
[DEBUG] Posting to validation endpoint: https://record-cleaner.brc.ac.uk/validate
[DEBUG] Request payload size: 10 records
[DEBUG] Validation API response status: 200
[INFO] Validation complete - received 10 validated records
[DEBUG] Validation results: 8 pass, 1 warn, 1 fail
[INFO] Phase 2: Preparing records for verification
[INFO] Prepared 8 records for verification (out of 10 validated)
[INFO] Phase 3: Verification
[INFO] Verifying 8 records via Record Cleaner API
[DEBUG] Using existing valid Record Cleaner token
[DEBUG] Posting to verification endpoint: https://record-cleaner.brc.ac.uk/verify
[DEBUG] Request payload size: 8 records
[DEBUG] Verification API response status: 200
[INFO] Verification complete - received 8 verified records
[DEBUG] Verification results: 6 pass, 1 warn, 1 fail
[DEBUG] Verification processing time: 1234.56ms
[INFO] ============================================================
[INFO] Validate and verify workflow complete: 10 validated, 8 verified
[INFO] ============================================================
[INFO] Validation complete: 10 records validated
[INFO] Verification complete: 8 records verified
[INFO] STEP 6: Merging validation/verification results with original occurrences
[DEBUG] Merged 10 records
[DEBUG] STEP 7: Generating summary statistics
[INFO] Summary: Validation pass rate: 80.0%, Verification pass rate: 75.0%
[DEBUG] STEP 8: Storing results in session for CSV download
[DEBUG] STEP 9: Preparing context and rendering results template
[INFO] ================================================================================
[INFO] Record Cleaner report generation completed successfully
[INFO] ================================================================================
```

## Troubleshooting

### No Logs Appearing?
1. Make sure Django's `DEBUG = True` in settings
2. Check that the logging configuration is in `config/settings.py`
3. Restart the Django development server

### Too Many Logs?
To reduce log verbosity, edit `config/settings.py` and change:
```python
'atlas_record_cleaner_report': {
    'handlers': ['console', 'file'],
    'level': 'INFO',  # Changed from 'DEBUG'
    'propagate': False,
},
```

### Log File Growing Too Large?
The log file automatically rotates at 10 MB. To change this:
```python
'file': {
    'class': 'logging.handlers.RotatingFileHandler',
    'filename': BASE_DIR / 'debug.log',
    'maxBytes': 5 * 1024 * 1024,  # 5 MB instead of 10 MB
    'backupCount': 3,  # Keep fewer backups
    'formatter': 'verbose',
},
```

## Configuration Location

All logging configuration is in:
```
/Users/hmj/Documents/code/devs-gone-wild-app/config/settings.py
```

Look for the `LOGGING` dictionary at the bottom of the file.