StarPunk/docs/reports/indieauth-detailed-logging-implementation.md

IndieAuth Detailed Logging Implementation Report

Date: 2025-11-19 Version: 0.7.0 Implementation: ADR-018 - IndieAuth Detailed Logging Strategy Developer: @agent-developer

Summary

Successfully implemented comprehensive, security-aware logging for IndieAuth authentication flows in StarPunk v0.7.0. The implementation provides detailed visibility into authentication processes while automatically protecting sensitive data through token redaction.

Implementation Overview

Files Modified

1. starpunk/auth.py - Authentication module

   • Added 3 logging helper functions (_redact_token, _log_http_request, _log_http_response)
   • Enhanced 4 authentication functions with logging (initiate_login, handle_callback, create_session, verify_session)
   • Added import for logging module

2. starpunk/init.py - Application initialization

   • Added configure_logging() function
   • Integrated logging configuration into create_app()
   • Added production warning for DEBUG logging

3. tests/test_auth.py - Authentication tests

   • Added 2 new test classes (TestLoggingHelpers, TestLoggingIntegration)
   • Added 14 new tests for logging functionality
   • Tests verify token redaction and logging behavior

4. CHANGELOG.md - Project changelog

   • Added v0.7.0 entry with comprehensive details

5. starpunk/init.py - Version number

   • Incremented from v0.6.2 to v0.7.0

Features Implemented

1. Token Redaction Helper

Function: _redact_token(value, show_chars=6)

Purpose: Safely redact sensitive tokens for logging

Behavior:

• Shows first N characters (default 6) and last 4 characters
• Redacts middle portion with asterisks
• Returns "REDACTED" for empty or short tokens

Example:

_redact_token("abcdefghijklmnopqrstuvwxyz", 6)
# Returns: "abcdef...********...wxyz"

2. HTTP Request Logging

Function: _log_http_request(method, url, data, headers=None)

Purpose: Log outgoing HTTP requests to IndieLogin.com

Features:

• Only logs at DEBUG level
• Automatically redacts "code" and "state" parameters
• Excludes sensitive headers (Authorization, Cookie)
• Early return if DEBUG not enabled (performance optimization)

Example Log Output:

DEBUG - Auth: IndieAuth HTTP Request:
  Method: POST
  URL: https://indielogin.com/auth
  Data: {
    'code': 'abc123...********...def9',
    'client_id': 'https://starpunk.example.com',
    'redirect_uri': 'https://starpunk.example.com/auth/callback'
  }

3. HTTP Response Logging

Function: _log_http_response(status_code, headers, body)

Purpose: Log incoming HTTP responses from IndieLogin.com

Features:

• Only logs at DEBUG level
• Parses and redacts JSON bodies
• Redacts access_token and code fields
• Excludes sensitive headers (Set-Cookie, Authorization)
• Handles non-JSON responses gracefully

Example Log Output:

DEBUG - Auth: IndieAuth HTTP Response:
  Status: 200
  Headers: {'content-type': 'application/json'}
  Body: {
    "me": "https://example.com"
  }

4. Authentication Flow Logging

Enhanced all authentication functions with structured logging:

initiate_login()

• DEBUG: URL validation
• DEBUG: State token generation (redacted)
• DEBUG: Authorization URL construction with parameters
• INFO: Authentication initiation milestone

handle_callback()

• DEBUG: State token verification (redacted)
• WARNING: Invalid state token received
• DEBUG: State token consumption
• DEBUG: HTTP request to IndieLogin.com (via helper)
• DEBUG: HTTP response from IndieLogin.com (via helper)
• ERROR: Request/response failures
• DEBUG: Identity received
• INFO: Admin verification check
• WARNING: Unauthorized login attempts
• DEBUG: Admin verification passed

create_session()

• DEBUG: Session token generation
• DEBUG: Session expiry calculation
• DEBUG: Request metadata (IP, User-Agent)
• INFO: Session creation milestone

verify_session()

• DEBUG: Session token verification (redacted)
• DEBUG: Session validation result

5. Logger Configuration

Function: configure_logging(app)

Purpose: Configure Flask logger based on LOG_LEVEL environment variable

Features:

• Supports DEBUG, INFO, WARNING, ERROR levels
• Detailed format for DEBUG: [timestamp] LEVEL - name: message
• Concise format for other levels: [timestamp] LEVEL: message
• Production warning if DEBUG enabled in non-development environment
• Clears existing handlers to avoid duplicates

Production Warning:

======================================================================
WARNING: DEBUG logging enabled in production!
This logs detailed HTTP requests/responses.
Sensitive data is redacted, but consider using INFO level.
Set LOG_LEVEL=INFO in production for normal operation.
======================================================================

Security Measures

Automatic Redaction

All sensitive data is automatically redacted in logs:

Data Type	Redaction Pattern	Example
Authorization codes	First 6, last 4	abc123...********...xyz9
State tokens	First 8, last 4	a1b2c3d4...********...wxyz
Session tokens	First 6, last 4	token1...********...end1
Access tokens	First 6, last 4	secret...********...x789

Sensitive Header Exclusion

The following headers are never logged:

• Authorization
• Cookie
• Set-Cookie

No Plaintext Tokens

Session tokens are never logged in plaintext - only their hashes are stored in the database, and logs show only redacted versions.

Production Warning

Clear warning logged if DEBUG level is enabled in a non-development environment, recommending INFO level for normal production operation.

Testing

Test Coverage

New Tests Added: 14 Test Classes Added: 2 (TestLoggingHelpers, TestLoggingIntegration) Total Auth Tests: 51 (all passing) Pass Rate: 100%

Test Categories

Helper Function Tests (7 tests)

• test_redact_token_normal
• test_redact_token_short
• test_redact_token_empty
• test_redact_token_custom_length
• test_log_http_request_redacts_code
• test_log_http_request_redacts_state
• test_log_http_request_not_logged_at_info
• test_log_http_response_redacts_tokens
• test_log_http_response_handles_non_json
• test_log_http_response_redacts_sensitive_headers

Integration Tests (4 tests)

• test_initiate_login_logs_at_debug
• test_initiate_login_info_level
• test_handle_callback_logs_http_details
• test_create_session_logs_details

Security Test Results

All tests verify:

• ✅ No complete tokens appear in logs
• ✅ Redaction pattern is correct
• ✅ Sensitive headers are excluded
• ✅ DEBUG logging doesn't occur at INFO level
• ✅ Token lifecycle can be tracked via redacted values

Configuration

Environment Variables

LOG_LEVEL (optional, default: INFO)

• DEBUG: Full HTTP request/response logging with redaction
• INFO: Flow milestones only (recommended for production)
• WARNING: Only warnings and errors
• ERROR: Only errors

Example .env Configuration:

# Development
LOG_LEVEL=DEBUG

# Production
LOG_LEVEL=INFO

Usage Examples

Example 1: Successful Authentication Flow (DEBUG)

[2025-11-19 14:30:00] DEBUG - Auth: Validating me URL: https://example.com
[2025-11-19 14:30:00] DEBUG - Auth: Generated state token: a1b2c3d4...********...wxyz
[2025-11-19 14:30:00] DEBUG - Auth: Building authorization URL with params: {
  'me': 'https://example.com',
  'client_id': 'https://starpunk.example.com',
  'redirect_uri': 'https://starpunk.example.com/auth/callback',
  'state': 'a1b2c3d4...********...wxyz',
  'response_type': 'code'
}
[2025-11-19 14:30:00] INFO - Auth: Authentication initiated for https://example.com
[2025-11-19 14:30:15] DEBUG - Auth: Verifying state token: a1b2c3d4...********...wxyz
[2025-11-19 14:30:15] DEBUG - Auth: State token valid and consumed
[2025-11-19 14:30:15] DEBUG - Auth: IndieAuth HTTP Request:
  Method: POST
  URL: https://indielogin.com/auth
  Data: {
    'code': 'xyz789...********...abc1',
    'client_id': 'https://starpunk.example.com',
    'redirect_uri': 'https://starpunk.example.com/auth/callback'
  }
[2025-11-19 14:30:16] DEBUG - Auth: IndieAuth HTTP Response:
  Status: 200
  Headers: {'content-type': 'application/json'}
  Body: {
    "me": "https://example.com"
  }
[2025-11-19 14:30:16] DEBUG - Auth: Received identity from IndieLogin: https://example.com
[2025-11-19 14:30:16] INFO - Auth: Verifying admin authorization for me=https://example.com
[2025-11-19 14:30:16] DEBUG - Auth: Admin verification passed
[2025-11-19 14:30:16] DEBUG - Auth: Session token generated (hash will be stored)
[2025-11-19 14:30:16] DEBUG - Auth: Session expiry: 2025-12-19 14:30:16 (30 days)
[2025-11-19 14:30:16] DEBUG - Auth: Request metadata - IP: 192.168.1.100, User-Agent: Mozilla/5.0...
[2025-11-19 14:30:16] INFO - Auth: Session created for https://example.com

Example 2: Failed Authentication (INFO Level)

[2025-11-19 14:35:00] INFO - Auth: Authentication initiated for https://unauthorized.example.com
[2025-11-19 14:35:15] WARNING - Auth: Unauthorized login attempt: https://unauthorized.example.com (expected https://authorized.example.com)

Example 3: IndieLogin Service Error (DEBUG)

[2025-11-19 14:40:15] DEBUG - Auth: Verifying state token: def456...********...ghi9
[2025-11-19 14:40:15] DEBUG - Auth: State token valid and consumed
[2025-11-19 14:40:15] DEBUG - Auth: IndieAuth HTTP Request:
  Method: POST
  URL: https://indielogin.com/auth
  Data: {
    'code': 'pqr789...********...stu1',
    'client_id': 'https://starpunk.example.com',
    'redirect_uri': 'https://starpunk.example.com/auth/callback'
  }
[2025-11-19 14:40:16] DEBUG - Auth: IndieAuth HTTP Response:
  Status: 400
  Headers: {'content-type': 'application/json'}
  Body: {
    "error": "invalid_grant",
    "error_description": "The authorization code is invalid or has expired"
  }
[2025-11-19 14:40:16] ERROR - Auth: IndieLogin returned error: 400

Performance Considerations

DEBUG Level Overhead

• String formatting only performed if DEBUG is enabled (early return)
• Minimal overhead at INFO/WARNING/ERROR levels
• Token redaction is O(1) operation (simple string slicing)
• Log volume increases significantly at DEBUG level

Recommendations

Development: Use DEBUG for full visibility during development and troubleshooting

Production: Use INFO for normal operation, only enable DEBUG temporarily for troubleshooting specific issues

Standards Compliance

OWASP Logging Cheat Sheet

✅ Sensitive data is never logged in full ✅ Redaction protects while maintaining debuggability ✅ Security events are logged (authentication attempts) ✅ Context is included (IP, User-Agent)

Python Logging Best Practices

✅ Uses standard logging module ✅ Appropriate log levels for different events ✅ Structured, consistent log format ✅ Logger configuration in application factory

IndieAuth Specification

✅ Logging doesn't interfere with auth flow ✅ No specification violations ✅ Fully compatible with IndieAuth servers

Known Issues and Limitations

Pre-Existing Test Failure

One pre-existing test failure in tests/test_routes_dev_auth.py::TestConfigurationValidation::test_dev_mode_requires_dev_admin_me is unrelated to this implementation. The test expects a ValueError when DEV_ADMIN_ME is missing, but the .env file in the project root provides a default value that is loaded by dotenv, preventing the validation error. This is a test environment issue, not a code issue.

Resolution: Future work should address test isolation to prevent .env file from affecting tests.

Future Enhancements

Potential improvements for V2+:

1. Structured JSON Logging: Machine-readable format for log aggregation
2. Request ID Tracking: Trace requests across multiple log entries
3. Performance Metrics: Log timing for each auth step
4. Log Rotation: Automatic log file management
5. Audit Trail: Separate audit log for security events
6. OpenTelemetry: Distributed tracing support

Conclusion

The IndieAuth detailed logging implementation successfully enhances StarPunk's debuggability while maintaining strong security practices. All 14 new tests pass, no complete tokens appear in logs, and the system provides excellent visibility into authentication flows at DEBUG level while remaining quiet at INFO level for production use.

The implementation exactly follows the architect's specification in ADR-018, uses security-first design with automatic redaction, and complies with industry standards (OWASP, Python logging best practices).

Version History

• v0.7.0 (2025-11-19): Initial implementation of IndieAuth detailed logging
• Based on: ADR-018 - IndieAuth Detailed Logging Strategy

Related Documentation

• ADR-018: IndieAuth Detailed Logging Strategy
• Versioning Strategy
• CHANGELOG.md