836 lines
25 KiB
Markdown
Raw Normal View History

# Unified Logging System
The TCP Dashboard project uses a unified logging system that provides consistent, centralized logging across all components with advanced conditional logging capabilities.
## Features
- **Component-specific directories**: Each component gets its own log directory
- **Date-based file rotation**: New log files created daily automatically
- **Unified format**: Consistent timestamp and message format across all logs
- **Thread-safe**: Safe for use in multi-threaded applications
- **Verbose console logging**: Configurable console output with proper log level handling
- **Automatic log cleanup**: Built-in functionality to remove old log files automatically
- **Error handling**: Graceful fallback to console logging if file logging fails
- **Conditional logging**: Components can operate with or without loggers
- **Error-only logging**: Option to log only error-level messages
- **Hierarchical logging**: Parent components can pass loggers to children
- **Logger inheritance**: Consistent logging across component hierarchies
## Conditional Logging System
The TCP Dashboard implements a sophisticated conditional logging system that allows components to work with or without loggers, providing maximum flexibility for different deployment scenarios.
### Key Concepts
1. **Optional Logging**: Components accept `logger=None` and function normally without logging
2. **Error-Only Mode**: Components can log only error-level messages with `log_errors_only=True`
3. **Logger Inheritance**: Parent components pass their logger to child components
4. **Hierarchical Structure**: Log files are organized by component hierarchy
2025-06-03 12:08:43 +08:00
### Component Hierarchy
```
Top-level Application (individual logger)
├── ProductionManager (individual logger)
│ ├── DataSaver (receives logger from ProductionManager)
│ ├── DataValidator (receives logger from ProductionManager)
│ ├── DatabaseConnection (receives logger from ProductionManager)
│ └── CollectorManager (individual logger)
│ ├── OKX collector BTC-USD (individual logger)
│ │ ├── DataAggregator (receives logger from OKX collector)
│ │ ├── DataTransformer (receives logger from OKX collector)
│ │ └── DataProcessor (receives logger from OKX collector)
│ └── Another collector...
```
### Usage Patterns
#### 1. No Logging
```python
from data.collector_manager import CollectorManager
from data.exchanges.okx.collector import OKXCollector
# Components work without any logging
manager = CollectorManager(logger=None)
collector = OKXCollector("BTC-USDT", logger=None)
# No log files created, no console output
# Components function normally without exceptions
```
#### 2. Normal Logging
```python
from utils.logger import get_logger
from data.collector_manager import CollectorManager
# Create logger for the manager
logger = get_logger('production_manager')
# Manager logs all activities
manager = CollectorManager(logger=logger)
# Child components inherit the logger
collector = manager.add_okx_collector("BTC-USDT") # Uses manager's logger
```
#### 3. Error-Only Logging
```python
from utils.logger import get_logger
from data.exchanges.okx.collector import OKXCollector
# Create logger but only log errors
logger = get_logger('critical_only')
# Only error and critical messages are logged
collector = OKXCollector(
"BTC-USDT",
logger=logger,
log_errors_only=True
)
# Debug, info, warning messages are suppressed
# Error and critical messages are always logged
```
#### 4. Hierarchical Logging
```python
from utils.logger import get_logger
from data.collector_manager import CollectorManager
# Top-level application logger
app_logger = get_logger('tcp_dashboard')
# Production manager with its own logger
prod_logger = get_logger('production_manager')
manager = CollectorManager(logger=prod_logger)
# Individual collectors with specific loggers
btc_logger = get_logger('btc_collector')
btc_collector = OKXCollector("BTC-USDT", logger=btc_logger)
eth_collector = OKXCollector("ETH-USDT", logger=None) # No logging
# Results in organized log structure:
# logs/tcp_dashboard/
# logs/production_manager/
# logs/btc_collector/
# (no logs for ETH collector)
```
#### 5. Mixed Configuration
```python
from utils.logger import get_logger
from data.collector_manager import CollectorManager
# System logger for normal operations
system_logger = get_logger('system')
# Critical logger for error-only components
critical_logger = get_logger('critical_only')
manager = CollectorManager(logger=system_logger)
# Different logging strategies for different collectors
btc_collector = OKXCollector("BTC-USDT", logger=system_logger) # Full logging
eth_collector = OKXCollector("ETH-USDT", logger=critical_logger, log_errors_only=True) # Errors only
ada_collector = OKXCollector("ADA-USDT", logger=None) # No logging
manager.add_collector(btc_collector)
manager.add_collector(eth_collector)
manager.add_collector(ada_collector)
```
### Implementation Details
#### Component Constructor Pattern
All major components follow this pattern:
```python
class ComponentExample:
def __init__(self, logger=None, log_errors_only=False):
self.logger = logger
self.log_errors_only = log_errors_only
2025-06-03 12:08:43 +08:00
def _log_debug(self, message: str) -> None:
"""Log debug message if logger is available and not in errors-only mode."""
if self.logger and not self.log_errors_only:
self.logger.debug(message)
2025-06-03 12:08:43 +08:00
def _log_info(self, message: str) -> None:
"""Log info message if logger is available and not in errors-only mode."""
if self.logger and not self.log_errors_only:
self.logger.info(message)
def _log_warning(self, message: str) -> None:
"""Log warning message if logger is available and not in errors-only mode."""
if self.logger and not self.log_errors_only:
self.logger.warning(message)
def _log_error(self, message: str, exc_info: bool = False) -> None:
"""Log error message if logger is available (always logs errors)."""
if self.logger:
self.logger.error(message, exc_info=exc_info)
def _log_critical(self, message: str, exc_info: bool = False) -> None:
"""Log critical message if logger is available (always logs critical)."""
if self.logger:
self.logger.critical(message, exc_info=exc_info)
```
#### Child Component Pattern
Child components receive logger from parent:
```python
class OKXCollector(BaseDataCollector):
def __init__(self, symbol: str, logger=None, log_errors_only=False):
super().__init__(..., logger=logger, log_errors_only=log_errors_only)
2025-06-03 12:08:43 +08:00
# Pass logger to child components
self._data_processor = OKXDataProcessor(
symbol,
logger=self.logger # Pass parent's logger
)
self._data_validator = DataValidator(logger=self.logger)
self._data_transformer = DataTransformer(logger=self.logger)
```
#### Supported Components
The following components support conditional logging:
1. **BaseDataCollector** (`data/base_collector.py`)
- Parameters: `logger=None, log_errors_only=False`
- Conditional logging for all collector operations
2. **CollectorManager** (`data/collector_manager.py`)
- Parameters: `logger=None, log_errors_only=False`
- Manages multiple collectors with consistent logging
3. **OKXCollector** (`data/exchanges/okx/collector.py`)
- Parameters: `logger=None, log_errors_only=False`
- Exchange-specific data collection with conditional logging
4. **BaseDataValidator** (`data/common/validation.py`)
- Parameters: `logger=None`
- Data validation with optional logging
5. **OKXDataTransformer** (`data/exchanges/okx/data_processor.py`)
- Parameters: `logger=None`
- Data processing with conditional logging
## Basic Usage
### Import and Initialize
```python
from utils.logger import get_logger
# Basic usage - gets logger with default settings
logger = get_logger('bot_manager')
# With verbose console output
logger = get_logger('bot_manager', verbose=True)
# With custom cleanup settings
logger = get_logger('bot_manager', clean_old_logs=True, max_log_files=7)
# All parameters
logger = get_logger(
component_name='bot_manager',
log_level='DEBUG',
verbose=True,
clean_old_logs=True,
max_log_files=14
)
```
### Log Messages
```python
# Different log levels
logger.debug("Detailed debugging information")
logger.info("General information about program execution")
logger.warning("Something unexpected happened")
logger.error("An error occurred", exc_info=True) # Include stack trace
logger.critical("A critical error occurred")
```
### Complete Example
```python
from utils.logger import get_logger
class BotManager:
def __init__(self):
# Initialize with verbose output and keep only 7 days of logs
self.logger = get_logger('bot_manager', verbose=True, max_log_files=7)
self.logger.info("BotManager initialized")
def start_bot(self, bot_id: str):
try:
self.logger.info(f"Starting bot {bot_id}")
# Bot startup logic here
self.logger.info(f"Bot {bot_id} started successfully")
except Exception as e:
self.logger.error(f"Failed to start bot {bot_id}: {e}", exc_info=True)
raise
def stop_bot(self, bot_id: str):
self.logger.info(f"Stopping bot {bot_id}")
# Bot shutdown logic here
self.logger.info(f"Bot {bot_id} stopped")
```
2025-06-03 12:08:43 +08:00
## Log Format
All log messages follow this unified format:
```
[YYYY-MM-DD HH:MM:SS - LEVEL - message]
```
Example:
```
[2024-01-15 14:30:25 - INFO - Bot started successfully]
[2024-01-15 14:30:26 - ERROR - Connection failed: timeout]
```
## File Organization
Logs are organized in a hierarchical structure:
```
logs/
├── tcp_dashboard/
│ ├── 2024-01-15.txt
│ └── 2024-01-16.txt
├── production_manager/
│ ├── 2024-01-15.txt
│ └── 2024-01-16.txt
├── collector_manager/
│ └── 2024-01-15.txt
├── okx_collector_btc_usdt/
│ └── 2024-01-15.txt
└── okx_collector_eth_usdt/
└── 2024-01-15.txt
```
## Configuration
### Logger Parameters
The `get_logger()` function accepts several parameters for customization:
```python
get_logger(
component_name: str, # Required: component name
log_level: str = "INFO", # Log level: DEBUG, INFO, WARNING, ERROR, CRITICAL
verbose: Optional[bool] = None, # Console logging: True, False, or None (use env)
clean_old_logs: bool = True, # Auto-cleanup old logs
max_log_files: int = 30 # Max number of log files to keep
)
```
### Log Levels
Set the log level when getting a logger:
```python
# Available levels: DEBUG, INFO, WARNING, ERROR, CRITICAL
logger = get_logger('component_name', 'DEBUG') # Show all messages
logger = get_logger('component_name', 'ERROR') # Show only errors and critical
```
### Verbose Console Logging
Control console output with the `verbose` parameter:
```python
# Explicit verbose settings
logger = get_logger('bot_manager', verbose=True) # Always show console logs
logger = get_logger('bot_manager', verbose=False) # Never show console logs
# Use environment variable (default behavior)
logger = get_logger('bot_manager', verbose=None) # Uses VERBOSE_LOGGING from .env
```
Environment variables for console logging:
```bash
# In .env file or environment
VERBOSE_LOGGING=true # Enable verbose console logging
LOG_TO_CONSOLE=true # Alternative environment variable (backward compatibility)
```
Console output respects log levels:
- **DEBUG level**: Shows all messages (DEBUG, INFO, WARNING, ERROR, CRITICAL)
- **INFO level**: Shows INFO and above (INFO, WARNING, ERROR, CRITICAL)
- **WARNING level**: Shows WARNING and above (WARNING, ERROR, CRITICAL)
- **ERROR level**: Shows ERROR and above (ERROR, CRITICAL)
- **CRITICAL level**: Shows only CRITICAL messages
### Automatic Log Cleanup
Control automatic cleanup of old log files:
```python
# Enable automatic cleanup (default)
logger = get_logger('bot_manager', clean_old_logs=True, max_log_files=7)
# Disable automatic cleanup
logger = get_logger('bot_manager', clean_old_logs=False)
# Custom retention (keep 14 most recent log files)
logger = get_logger('bot_manager', max_log_files=14)
```
**How automatic cleanup works:**
- Triggered every time a new log file is created (date change)
- Keeps only the most recent `max_log_files` files
- Deletes older files automatically
- Based on file modification time, not filename
2025-06-03 12:08:43 +08:00
## Best Practices for Conditional Logging
### 1. Logger Inheritance
```python
# Parent component creates logger
parent_logger = get_logger('parent_system')
parent = ParentComponent(logger=parent_logger)
# Pass logger to children for consistent hierarchy
child1 = ChildComponent(logger=parent_logger)
child2 = ChildComponent(logger=parent_logger, log_errors_only=True)
child3 = ChildComponent(logger=None) # No logging
```
### 2. Environment-Based Configuration
```python
import os
from utils.logger import get_logger
def create_system_logger():
"""Create logger based on environment."""
env = os.getenv('ENVIRONMENT', 'development')
if env == 'production':
return get_logger('production_system', log_level='INFO', verbose=False)
elif env == 'testing':
return None # No logging during tests
else:
return get_logger('dev_system', log_level='DEBUG', verbose=True)
# Use in components
system_logger = create_system_logger()
manager = CollectorManager(logger=system_logger)
```
### 3. Conditional Error-Only Mode
```python
def create_collector_with_logging_strategy(symbol, strategy='normal'):
"""Create collector with different logging strategies."""
base_logger = get_logger(f'collector_{symbol.lower().replace("-", "_")}')
if strategy == 'silent':
return OKXCollector(symbol, logger=None)
elif strategy == 'errors_only':
return OKXCollector(symbol, logger=base_logger, log_errors_only=True)
else:
return OKXCollector(symbol, logger=base_logger)
# Usage
btc_collector = create_collector_with_logging_strategy('BTC-USDT', 'normal')
eth_collector = create_collector_with_logging_strategy('ETH-USDT', 'errors_only')
ada_collector = create_collector_with_logging_strategy('ADA-USDT', 'silent')
```
### 4. Performance Optimization
```python
class OptimizedComponent:
def __init__(self, logger=None, log_errors_only=False):
self.logger = logger
self.log_errors_only = log_errors_only
# Pre-compute logging capabilities for performance
self.can_log_debug = logger and not log_errors_only
self.can_log_info = logger and not log_errors_only
self.can_log_warning = logger and not log_errors_only
self.can_log_error = logger is not None
self.can_log_critical = logger is not None
def process_data(self, data):
if self.can_log_debug:
self.logger.debug(f"Processing {len(data)} records")
# ... processing logic ...
if self.can_log_info:
self.logger.info("Data processing completed")
```
## Advanced Features
### Manual Log Cleanup
Remove old log files manually based on age:
```python
from utils.logger import cleanup_old_logs
# Remove logs older than 30 days for a specific component
cleanup_old_logs('bot_manager', days_to_keep=30)
# Or clean up logs for multiple components
for component in ['bot_manager', 'data_collector', 'strategies']:
cleanup_old_logs(component, days_to_keep=7)
```
### Error Handling with Context
```python
try:
risky_operation()
except Exception as e:
logger.error(f"Operation failed: {e}", exc_info=True)
# exc_info=True includes the full stack trace
```
### Structured Logging
For complex data, use structured messages:
```python
# Good: Structured information
logger.info(f"Trade executed: symbol={symbol}, price={price}, quantity={quantity}")
# Even better: JSON-like structure for parsing
logger.info(f"Trade executed", extra={
'symbol': symbol,
'price': price,
'quantity': quantity,
'timestamp': datetime.now().isoformat()
})
```
## Configuration Examples
### Development Environment
```python
# Verbose logging with frequent cleanup
logger = get_logger(
'bot_manager',
log_level='DEBUG',
verbose=True,
max_log_files=3 # Keep only 3 days of logs
)
```
### Production Environment
```python
# Minimal console output with longer retention
logger = get_logger(
'bot_manager',
log_level='INFO',
verbose=False,
max_log_files=30 # Keep 30 days of logs
)
```
### Testing Environment
```python
# Disable cleanup for testing
logger = get_logger(
'test_component',
log_level='DEBUG',
verbose=True,
clean_old_logs=False # Don't delete logs during tests
)
```
## Environment Variables
Create a `.env` file to control default logging behavior:
```bash
# Enable verbose console logging globally
VERBOSE_LOGGING=true
# Alternative (backward compatibility)
LOG_TO_CONSOLE=true
```
## Best Practices
### 1. Component Naming
Use descriptive, consistent component names:
- `bot_manager` - for bot lifecycle management
- `data_collector` - for market data collection
- `strategies` - for trading strategies
- `backtesting` - for backtesting engine
- `dashboard` - for web dashboard
### 2. Log Level Guidelines
- **DEBUG**: Detailed diagnostic information, typically only of interest when diagnosing problems
- **INFO**: General information about program execution
- **WARNING**: Something unexpected happened, but the program is still working
- **ERROR**: A serious problem occurred, the program couldn't perform a function
- **CRITICAL**: A serious error occurred, the program may not be able to continue
### 3. Verbose Logging Guidelines
```python
# Development: Use verbose logging with DEBUG level
dev_logger = get_logger('component', 'DEBUG', verbose=True, max_log_files=3)
# Production: Use INFO level with no console output
prod_logger = get_logger('component', 'INFO', verbose=False, max_log_files=30)
# Testing: Disable cleanup to preserve test logs
test_logger = get_logger('test_component', 'DEBUG', verbose=True, clean_old_logs=False)
```
### 4. Log Retention Guidelines
```python
# High-frequency components (data collectors): shorter retention
data_logger = get_logger('data_collector', max_log_files=7)
# Important components (bot managers): longer retention
bot_logger = get_logger('bot_manager', max_log_files=30)
# Development: very short retention
dev_logger = get_logger('dev_component', max_log_files=3)
```
### 5. Message Content
```python
# Good: Descriptive and actionable
logger.error("Failed to connect to OKX API: timeout after 30s")
# Bad: Vague and unhelpful
logger.error("Error occurred")
# Good: Include relevant context
logger.info(f"Bot {bot_id} executed trade: {symbol} {side} {quantity}@{price}")
# Good: Include duration for performance monitoring
start_time = time.time()
# ... do work ...
duration = time.time() - start_time
logger.info(f"Data aggregation completed in {duration:.2f}s")
```
### 6. Exception Handling
```python
try:
execute_trade(symbol, quantity, price)
logger.info(f"Trade executed successfully: {symbol}")
except APIError as e:
logger.error(f"API error during trade execution: {e}", exc_info=True)
raise
except ValidationError as e:
logger.warning(f"Trade validation failed: {e}")
return False
except Exception as e:
logger.critical(f"Unexpected error during trade execution: {e}", exc_info=True)
raise
```
### 7. Performance Considerations
```python
# Good: Efficient string formatting
logger.debug(f"Processing {len(data)} records")
# Avoid: Expensive operations in log messages unless necessary
# logger.debug(f"Data: {expensive_serialization(data)}") # Only if needed
# Better: Check log level first for expensive operations
if logger.isEnabledFor(logging.DEBUG):
logger.debug(f"Data: {expensive_serialization(data)}")
```
2025-06-03 12:08:43 +08:00
## Migration Guide
2025-06-03 12:08:43 +08:00
### Updating Existing Components
2025-06-03 12:08:43 +08:00
1. **Add logger parameter to constructor**:
```python
def __init__(self, ..., logger=None, log_errors_only=False):
```
2. **Add conditional logging helpers**:
```python
def _log_debug(self, message: str) -> None:
if self.logger and not self.log_errors_only:
self.logger.debug(message)
```
3. **Update all logging calls**:
```python
# Before
self.logger.info("Message")
2025-06-03 12:08:43 +08:00
# After
self._log_info("Message")
```
4. **Pass logger to child components**:
```python
child = ChildComponent(logger=self.logger)
```
2025-06-03 12:08:43 +08:00
### From Standard Logging
```python
# Old logging (if any existed)
import logging
logging.basicConfig(level=logging.INFO)
logger = logging.getLogger(__name__)
# New unified logging
from utils.logger import get_logger
logger = get_logger('component_name', verbose=True)
```
2025-06-03 12:08:43 +08:00
### Gradual Adoption
1. **Phase 1**: Add optional logger parameters to new components
2. **Phase 2**: Update existing components to support conditional logging
3. **Phase 3**: Implement hierarchical logging structure
4. **Phase 4**: Add error-only logging mode
## Testing
2025-06-03 12:08:43 +08:00
### Testing Conditional Logging
2025-06-03 12:08:43 +08:00
#### Test Script Example
```python
# test_conditional_logging.py
from utils.logger import get_logger
from data.collector_manager import CollectorManager
from data.exchanges.okx.collector import OKXCollector
2025-06-03 12:08:43 +08:00
def test_no_logging():
"""Test components work without loggers."""
manager = CollectorManager(logger=None)
collector = OKXCollector("BTC-USDT", logger=None)
print("✓ No logging test passed")
2025-06-03 12:08:43 +08:00
def test_with_logging():
"""Test components work with loggers."""
logger = get_logger('test_system')
manager = CollectorManager(logger=logger)
collector = OKXCollector("BTC-USDT", logger=logger)
print("✓ With logging test passed")
2025-06-03 12:08:43 +08:00
def test_error_only():
"""Test error-only logging mode."""
logger = get_logger('test_errors')
collector = OKXCollector("BTC-USDT", logger=logger, log_errors_only=True)
print("✓ Error-only logging test passed")
if __name__ == "__main__":
test_no_logging()
test_with_logging()
test_error_only()
print("✅ All conditional logging tests passed!")
```
### Testing Changes
```python
2025-06-03 12:08:43 +08:00
# Test without logger
component = MyComponent(logger=None)
# Should work without errors, no logging
2025-06-03 12:08:43 +08:00
# Test with logger
logger = get_logger('test_component')
component = MyComponent(logger=logger)
# Should log normally
# Test error-only mode
component = MyComponent(logger=logger, log_errors_only=True)
# Should only log errors
```
2025-06-03 12:08:43 +08:00
### Basic System Test
2025-06-03 12:08:43 +08:00
Run a simple test to verify the logging system:
```bash
2025-06-03 12:08:43 +08:00
python -c "from utils.logger import get_logger; logger = get_logger('test', verbose=True); logger.info('Test message'); print('Check logs/test/ directory')"
```
## Troubleshooting
### Common Issues
1. **Permission errors**: Ensure the application has write permissions to the project directory
2. **Disk space**: Monitor disk usage and adjust log retention with `max_log_files`
3. **Threading issues**: The logger is thread-safe, but check for application-level concurrency issues
4. **Too many console messages**: Adjust `verbose` parameter or log levels
### Debug Mode
Enable debug logging to troubleshoot issues:
```python
logger = get_logger('component_name', 'DEBUG', verbose=True)
```
### Console Output Issues
```python
# Force console output regardless of environment
logger = get_logger('component_name', verbose=True)
# Check environment variables
import os
print(f"VERBOSE_LOGGING: {os.getenv('VERBOSE_LOGGING')}")
print(f"LOG_TO_CONSOLE: {os.getenv('LOG_TO_CONSOLE')}")
```
### Fallback Logging
If file logging fails, the system automatically falls back to console logging with a warning message.
2025-06-03 12:08:43 +08:00
## Integration with Existing Code
The logging system is designed to be gradually adopted:
2025-06-03 12:08:43 +08:00
1. **Start with new modules**: Use the unified logger in new code
2. **Replace existing logging**: Gradually migrate existing logging to the unified system
3. **No breaking changes**: Existing code continues to work
## Maintenance
### Automatic Cleanup Benefits
The automatic cleanup feature provides several benefits:
- **Disk space management**: Prevents log directories from growing indefinitely
- **Performance**: Fewer files to scan in log directories
- **Maintenance-free**: No need for external cron jobs or scripts
- **Component-specific**: Each component can have different retention policies
### Manual Cleanup for Special Cases
For cases requiring age-based cleanup instead of count-based:
```python
# cleanup_logs.py
from utils.logger import cleanup_old_logs
components = ['bot_manager', 'data_collector', 'strategies', 'dashboard']
for component in components:
cleanup_old_logs(component, days_to_keep=30)
```
### Monitoring Disk Usage
Monitor the `logs/` directory size and adjust retention policies as needed:
```bash
# Check log directory size
du -sh logs/
# Find large log files
find logs/ -name "*.txt" -size +10M
# Count log files per component
find logs/ -name "*.txt" | cut -d'/' -f2 | sort | uniq -c
```
2025-06-03 12:08:43 +08:00
This conditional logging system provides maximum flexibility while maintaining clean, maintainable code that works in all scenarios.