charieswei
/
TradingAgents
mirror of https://github.com/TauricResearch/TradingAgents.git
1
0
Fork 0
Code Issues Packages Projects Releases Wiki Activity

feat: Implement comprehensive logging system 

Adds a production-ready logging system with the following features:

## Core Features
- Structured logging with rich context and metadata
- Multiple log levels (DEBUG, INFO, WARNING, ERROR, CRITICAL)
- File and console output with separate handlers
- Automatic log rotation (prevents disk space issues)
- Component-specific loggers for different parts of the system
- Performance tracking with built-in metrics
- API call tracking with cost and token monitoring

## New Components
- tradingagents/utils/logging_config.py: Core logging module
  - TradingAgentsLogger: Main logger class
  - StructuredFormatter: Custom formatter with context
  - APICallLogger: Dedicated API call tracking
  - PerformanceLogger: Operation timing and metrics

## Log Files Created (in logs/ directory)
- tradingagents.log: All application logs (10MB rotation, 5 backups)
- errors.log: Errors only (5MB rotation, 3 backups)
- api_calls.log: API call tracking
- memory.log: Memory operations
- agents.log: Agent execution
- performance.log: Performance metrics

## Integration
- Updated memory.py: Full logging integration with context
  - Logs initialization, embeddings, add/get operations
  - Tracks API calls and performance
  - Provides detailed error context

- Updated trading_graph.py: Comprehensive graph logging
  - Logs initialization, propagation, reflection
  - Tracks component setup and execution
  - Performance metrics for all major operations

- Updated default_config.py: Added logging configuration
  - log_level, log_dir, log_to_console, log_to_file

## Documentation
- docs/LOGGING.md: Complete logging documentation (797 lines)
  - Quick start guide
  - Configuration examples
  - Best practices
  - API reference
  - Troubleshooting

## Benefits
- Better debugging and troubleshooting
- Production monitoring capabilities
- API cost tracking
- Performance analysis
- Audit trail for decisions
- Easier issue diagnosis

Tested and working. See docs/LOGGING.md for complete usage guide.
This commit is contained in:
Surapong Kanoktipsatharporn 2025-10-20 15:47:29 +07:00
parent 9dc69a931a
commit c9d3eff62e
9 changed files with 1606 additions and 31 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

2
.env.example
View File

@ -5,7 +5,7 @@ TRADINGAGENTS_LLM_PROVIDER=openai
TRADINGAGENTS_BACKEND_URL=https://api.openai.com/v1
# For OpenRouter
# OPENAI_API_KEY=your_openrouter_api_key_here # OpenRouter uses OPENAI_API_KEY env var
# OPENROUTER_API_KEY=your_openrouter_api_key_here # OpenRouter uses OPENAI_API_KEY env var
# ALPHA_VANTAGE_API_KEY=your_alpha_vantage_key_here
# TRADINGAGENTS_LLM_PROVIDER=openrouter
# TRADINGAGENTS_BACKEND_URL=https://openrouter.ai/api/v1

797
docs/LOGGING.md Normal file
View File

@ -0,0 +1,797 @@
# Comprehensive Logging System Documentation
**TradingAgents Logging System v1.0**
---
## Overview
TradingAgents now includes a comprehensive, production-ready logging system that provides:
- **Structured Logging**: Context-rich log messages with metadata
- **Multiple Log Levels**: DEBUG, INFO, WARNING, ERROR, CRITICAL
- **File and Console Output**: Separate handlers for different purposes
- **Log Rotation**: Automatic file rotation to prevent disk space issues
- **Component-Specific Loggers**: Dedicated loggers for different parts of the system
- **Performance Tracking**: Built-in performance metrics and timing
- **API Call Tracking**: Monitor API usage, costs, and errors
- **Easy Configuration**: Simple setup with sensible defaults
---
## Quick Start
### Basic Usage
```python
from tradingagents.utils import get_logger
# Get a logger for your component
logger = get_logger("tradingagents.my_component", component="MY_COMP")
# Log messages at different levels
logger.debug("Detailed debugging information")
logger.info("General information about execution")
logger.warning("Warning about potential issues")
logger.error("Error occurred but execution continues")
logger.critical("Critical error, system may be unstable")
```
### With Context
```python
logger.info(
"Processing trade decision",
extra={
"context": {
"ticker": "AAPL",
"decision": "BUY",
"confidence": 0.85,
"timestamp": "2025-01-15T10:30:00Z"
}
}
)
```
---
## Configuration
### Using Default Configuration
The logging system initializes automatically with defaults:
```python
from tradingagents.graph.trading_graph import TradingAgentsGraph
# Logging is automatically configured
graph = TradingAgentsGraph(["market", "news"])
```
### Custom Configuration
Configure logging settings in your config dictionary:
```python
config = {
# ... other config ...
# Logging settings
"log_level": "DEBUG", # More verbose logging
"log_dir": "custom_logs", # Custom log directory
"log_to_console": True, # Enable console output
"log_to_file": True, # Enable file output
}
graph = TradingAgentsGraph(["market"], config=config)
```
### Programmatic Configuration
```python
from tradingagents.utils import configure_logging, set_log_level
# Configure at application startup
configure_logging(
level="INFO", # Log level
log_dir="my_logs", # Custom directory
console=True # Console output
)
# Change log level at runtime
set_log_level("DEBUG")
```
---
## Log Levels
### DEBUG
**Use for**: Detailed diagnostic information
```python
logger.debug("Entering function with params: ticker=AAPL, date=2025-01-15")
logger.debug(f"Intermediate calculation: value={intermediate_result}")
```
**Output**: Only to log files (not console by default)
### INFO
**Use for**: General informational messages
```python
logger.info("Memory enabled with provider: openai")
logger.info("Propagation complete for AAPL")
```
**Output**: Console and log files
### WARNING
**Use for**: Potential issues that don't prevent execution
```python
logger.warning("Failed to get embedding for situation, skipping")
logger.warning("API rate limit approaching")
```
**Output**: Console and log files
### ERROR
**Use for**: Errors that prevent specific operations
```python
logger.error("Failed to initialize ChromaDB collection: Connection timeout")
logger.error(f"API call failed: {error_message}")
```
**Output**: Console, main log file, and errors.log
### CRITICAL
**Use for**: Severe errors that may crash the system
```python
logger.critical("Unable to initialize any LLM provider")
logger.critical("Database corruption detected")
```
**Output**: All handlers, highlighted in console
---
## Log Files
The logging system creates separate log files in the `logs/` directory:
### Main Logs
| File | Purpose | Rotation | Levels |
|------|---------|----------|--------|
| `tradingagents.log` | All application logs | 10 MB, 5 backups | DEBUG+ |
| `errors.log` | Errors only | 5 MB, 3 backups | ERROR+ |
| `api_calls.log` | API call tracking | 10 MB, 3 backups | INFO+ |
| `memory.log` | Memory operations | 10 MB, 3 backups | DEBUG+ |
| `agents.log` | Agent execution | 10 MB, 3 backups | INFO+ |
| `performance.log` | Performance metrics | 10 MB, 3 backups | INFO+ |
### Log Rotation
Files automatically rotate when they reach the size limit:
```
tradingagents.log # Current
tradingagents.log.1 # Previous
tradingagents.log.2 # Older
...
tradingagents.log.5 # Oldest (then deleted)
```
---
## Specialized Loggers
### API Call Logger
Track all API calls with detailed metrics:
```python
from tradingagents.utils import get_api_logger
api_logger = get_api_logger()
# Log successful API call
api_logger.log_call(
provider="openai",
model="gpt-4",
endpoint="/v1/chat/completions",
tokens=150,
cost=0.003,
duration=250.5,
status="success"
)
# Log failed API call
api_logger.log_call(
provider="openrouter",
model="llama-3",
endpoint="/v1/chat/completions",
status="error",
error="Connection timeout"
)
# Get statistics
stats = api_logger.get_stats()
print(f"Total calls: {stats['total_calls']}")
print(f"Total tokens: {stats['total_tokens']}")
```
**Output Format**:
```
2025-01-15 10:30:15 | INFO | API | API call to openai/gpt-4 - success
Context: {
"call_number": 42,
"provider": "openai",
"model": "gpt-4",
"endpoint": "/v1/chat/completions",
"tokens": 150,
"cost": 0.003,
"duration_ms": 250.5,
"status": "success"
}
```
### Performance Logger
Track operation timings and generate performance reports:
```python
from tradingagents.utils import get_performance_logger
import time
perf_logger = get_performance_logger()
# Log operation timing
start = time.time()
# ... do something ...
duration = (time.time() - start) * 1000
perf_logger.log_timing(
"analyst_execution",
duration,
context={"analyst": "market", "ticker": "AAPL"}
)
# Get average timing
avg = perf_logger.get_average_timing("analyst_execution")
print(f"Average time: {avg:.2f}ms")
# Log performance summary
perf_logger.log_summary()
```
**Summary Output**:
```
2025-01-15 10:35:00 | INFO | PERF | Performance Summary
Context: {
"analyst_execution": {
"count": 10,
"avg_ms": 1234.5,
"min_ms": 987.3,
"max_ms": 2100.8
},
"embedding_generation": {
"count": 25,
"avg_ms": 45.2,
"min_ms": 32.1,
"max_ms": 78.9
}
}
```
---
## Log Format
### Console Output
```
2025-01-15 10:30:15 | INFO | MEMORY | Added 5 situations to 'bull_memory'
2025-01-15 10:30:16 | WARNING | MEMORY | Failed to get embedding for situation 3, skipping
2025-01-15 10:30:17 | ERROR | API | API call failed: Connection timeout
```
Format: `{timestamp} | {level} | {component} | {message}`
### File Output
```
2025-01-15T10:30:15.123456 | INFO | tradingagents.memory | MEMORY | Added 5 situations to 'bull_memory'
Context: {
"collection": "bull_memory",
"count": 5,
"total_in_collection": 15,
"duration_ms": 123.45
}
```
Format: `{timestamp} | {level} | {logger_name} | {component} | {message}`
---
## Examples
### Memory Operations
```python
from tradingagents.agents.utils.memory import FinancialSituationMemory
config = {
"embedding_provider": "openai",
"enable_memory": True,
}
memory = FinancialSituationMemory("test_memory", config)
# Logs:
# INFO | MEMORY | Initialized embedding client for 'test_memory'
# INFO | MEMORY | Initialized ChromaDB collection 'test_memory'
# Add situations
memory.add_situations([
("High volatility", "Reduce positions"),
("Strong uptrend", "Scale in")
])
# Logs:
# DEBUG | MEMORY | Generated embedding for text (15 chars)
# DEBUG | MEMORY | Generated embedding for text (14 chars)
# INFO | MEMORY | Added 2 situations to 'test_memory'
# INFO | API | API call to openai/text-embedding-3-small - success
# Query memories
results = memory.get_memories("Market showing volatility", n_matches=1)
# Logs:
# DEBUG | MEMORY | Generated embedding for text (27 chars)
# INFO | MEMORY | Retrieved 1 memories from 'test_memory'
# INFO | PERF | get_memories completed in 45.23ms
```
### Trading Graph Execution
```python
from tradingagents.graph.trading_graph import TradingAgentsGraph
graph = TradingAgentsGraph(["market", "news"])
# Logs:
# INFO | GRAPH | Initializing TradingAgentsGraph
# INFO | GRAPH | Initializing chat LLMs with provider: openai
# INFO | GRAPH | Memory enabled with provider: openai
# INFO | MEMORY | Initialized embedding client for 'bull_memory'
# INFO | MEMORY | Initialized embedding client for 'bear_memory'
# ...
# INFO | GRAPH | TradingAgentsGraph initialization complete
# Run analysis
final_state, decision = graph.propagate("AAPL", "2025-01-15")
# Logs:
# INFO | GRAPH | Starting propagation for AAPL on 2025-01-15
# DEBUG | GRAPH | Starting graph execution
# DEBUG | GRAPH | Running in standard mode
# INFO | GRAPH | Propagation complete for AAPL
# INFO | PERF | propagation completed in 5432.1ms
```
### Error Handling
```python
# Failed API call
try:
response = client.embeddings.create(...)
except Exception as e:
logger.error(
f"Failed to get embedding: {e}",
extra={
"context": {
"provider": "openai",
"model": "text-embedding-3-small",
"error": str(e)
}
}
)
# Logs:
# ERROR | MEMORY | Failed to get embedding: 401 Unauthorized
# Context: {
# "provider": "openai",
# "model": "text-embedding-3-small",
# "error": "401 Unauthorized"
# }
# ERROR | API | API call to openai/text-embedding-3-small - error
# Context: {
# "provider": "openai",
# "model": "text-embedding-3-small",
# "endpoint": "embeddings.create",
# "status": "error",
# "error": "401 Unauthorized"
# }
```
---
## Best Practices
### 1. Use Appropriate Log Levels
```python
# ✅ Good
logger.debug(f"Processing item {i} of {total}") # Detailed info
logger.info("Analysis complete") # Important milestone
logger.warning("API rate limit at 80%") # Potential issue
logger.error("Failed to connect to database") # Actual error
# ❌ Bad
logger.info(f"i={i}, j={j}, k={k}") # Too detailed for INFO
logger.error("Successfully completed task") # Wrong level
```
### 2. Include Context
```python
# ✅ Good - Rich context
logger.info(
"Trade decision made",
extra={
"context": {
"ticker": "AAPL",
"decision": "BUY",
"confidence": 0.85,
"price": 150.50
}
}
)
# ❌ Bad - No context
logger.info("Trade decision made")
```
### 3. Log Performance Metrics
```python
# ✅ Good - Track timing
start_time = time.time()
result = expensive_operation()
duration = (time.time() - start_time) * 1000
perf_logger.log_timing(
"expensive_operation",
duration,
context={"items_processed": len(result)}
)
# ❌ Bad - No performance tracking
result = expensive_operation()
```
### 4. Log API Calls
```python
# ✅ Good - Track all API interactions
try:
start_time = time.time()
response = api_client.call(...)
duration = (time.time() - start_time) * 1000
api_logger.log_call(
provider="openai",
model="gpt-4",
endpoint="/v1/chat",
tokens=response.usage.total_tokens,
duration=duration,
status="success"
)
except Exception as e:
api_logger.log_call(
provider="openai",
model="gpt-4",
endpoint="/v1/chat",
status="error",
error=str(e)
)
# ❌ Bad - No API tracking
response = api_client.call(...)
```
### 5. Use Component Names
```python
# ✅ Good - Component identification
logger = get_logger("tradingagents.analyst.market", component="MARKET_ANALYST")
# ❌ Bad - Generic logger
logger = get_logger("tradingagents")
```
---
## Troubleshooting
### Logs Not Appearing
**Problem**: No logs in console or files
**Solution**:
1. Check log level: `set_log_level("DEBUG")`
2. Verify log directory exists and is writable
3. Check if logging was configured: `configure_logging(level="INFO")`
### Too Many Log Files
**Problem**: Log directory growing too large
**Solution**:
1. Reduce backup count in logging_config.py
2. Increase rotation size to rotate less frequently
3. Set up log cleanup cron job
### Performance Impact
**Problem**: Logging slowing down application
**Solution**:
1. Increase log level to WARNING or ERROR
2. Disable console logging: `configure_logging(console=False)`
3. Use async logging (future enhancement)
### Missing Context
**Problem**: Log messages don't show context dict
**Solution**:
1. Ensure you're using `extra={"context": {...}}`
2. Check that StructuredFormatter is being used
3. Verify logger is from TradingAgents system
---
## Advanced Usage
### Custom Logger Configuration
```python
from tradingagents.utils.logging_config import TradingAgentsLogger
# Get logger instance
logger_system = TradingAgentsLogger()
# Add custom file handler
logger_system.add_file_handler(
logger_name="tradingagents.custom",
filename="custom_component.log",
level=logging.INFO
)
# Get logger
logger = logger_system.get_logger(
"tradingagents.custom",
component="CUSTOM"
)
```
### Filtering Logs
View only specific components:
```bash
# Only memory logs
grep "MEMORY" logs/tradingagents.log
# Only errors
cat logs/errors.log
# API calls for specific provider
grep "openai" logs/api_calls.log
```
### Log Analysis
```bash
# Count error types
grep "ERROR" logs/tradingagents.log | cut -d'|' -f4 | sort | uniq -c
# API call statistics
grep "API call to" logs/api_calls.log | wc -l
# Performance summary
grep "Performance Summary" logs/performance.log -A 20
```
---
## Testing
### Test Logging System
```bash
# Run logging system tests
python -m tradingagents.utils.logging_config
# Output:
# Testing TradingAgents Logging System
# ======================================================================
# 2025-01-15 10:30:00 | INFO | TEST | This is an info message
# 2025-01-15 10:30:00 | WARNING | TEST | This is a warning message
# 2025-01-15 10:30:00 | ERROR | TEST | This is an error message
# ...
# Logging test complete. Check the 'logs' directory for output files.
```
### Verify Log Files
```bash
# Check log directory
ls -lh logs/
# Output:
# -rw-r--r-- tradingagents.log
# -rw-r--r-- api_calls.log
# -rw-r--r-- errors.log
# -rw-r--r-- performance.log
```
---
## Configuration Reference
### Config Parameters
```python
DEFAULT_CONFIG = {
# Logging settings
"log_level": "INFO", # DEBUG, INFO, WARNING, ERROR, CRITICAL
"log_dir": "logs", # Directory for log files
"log_to_console": True, # Enable console output
"log_to_file": True, # Enable file output
}
```
### Environment Variables
```bash
# Override log level
export TRADINGAGENTS_LOG_LEVEL=DEBUG
# Override log directory
export TRADINGAGENTS_LOG_DIR=/var/log/tradingagents
```
---
## API Reference
### get_logger()
```python
def get_logger(name: str = "tradingagents", component: Optional[str] = None) -> logging.Logger
```
Get a configured logger instance.
**Parameters**:
- `name`: Logger name (default: "tradingagents")
- `component`: Component name for context (optional)
**Returns**: Configured logger instance
### get_api_logger()
```python
def get_api_logger() -> APICallLogger
```
Get the API call tracking logger.
**Returns**: APICallLogger instance
### get_performance_logger()
```python
def get_performance_logger() -> PerformanceLogger
```
Get the performance tracking logger.
**Returns**: PerformanceLogger instance
### configure_logging()
```python
def configure_logging(
level: str = "INFO",
log_dir: Optional[str] = None,
console: bool = True
)
```
Configure the logging system.
**Parameters**:
- `level`: Log level (DEBUG, INFO, WARNING, ERROR, CRITICAL)
- `log_dir`: Directory for log files
- `console`: Whether to log to console
### set_log_level()
```python
def set_log_level(level: str)
```
Set the global log level.
**Parameters**:
- `level`: Log level string
---
## Migration from Print Statements
### Before
```python
print(f"Memory enabled with provider: {provider}")
print(f"Added {count} situations")
print(f"ERROR: Failed to connect: {error}")
```
### After
```python
logger.info(
f"Memory enabled with provider: {provider}",
extra={"context": {"provider": provider}}
)
logger.info(
f"Added {count} situations",
extra={"context": {"count": count}}
)
logger.error(
f"Failed to connect: {error}",
extra={"context": {"error": str(error)}}
)
```
---
## Future Enhancements
Planned improvements:
- [ ] Async logging for better performance
- [ ] Cloud logging integration (CloudWatch, Stackdriver)
- [ ] Real-time log streaming dashboard
- [ ] Log aggregation and analytics
- [ ] Structured JSON logging option
- [ ] Log compression for archived files
- [ ] Email alerts for critical errors
- [ ] Slack/Discord notifications
---
## Support
For questions or issues with the logging system:
1. Check this documentation
2. Review log files in `logs/` directory
3. Test with `python -m tradingagents.utils.logging_config`
4. Open GitHub issue with log samples
---
**Version**: 1.0
**Last Updated**: 2025-01-15
**Status**: Production Ready ✅

13
logs/errors.log Normal file
View File

@ -0,0 +1,13 @@
2025-10-20T08:46:44.237227 | ERROR | tradingagents.test | TEST | This is an error message
2025-10-20T08:46:44.237334 | ERROR | tradingagents.api | API | API call failed: Connection timeout
Context: {
"call_number": 2,
"provider": "openrouter",
"model": "llama-3",
"endpoint": "/v1/chat/completions",
"tokens": null,
"cost": null,
"duration_ms": null,
"status": "error",
"error": "Connection timeout"
}

48
logs/tradingagents.log Normal file
View File

@ -0,0 +1,48 @@
2025-10-20T08:46:44.236932 | DEBUG | tradingagents.test | TEST | This is a debug message
2025-10-20T08:46:44.237168 | INFO | tradingagents.test | TEST | This is an info message
2025-10-20T08:46:44.237198 | WARNING | tradingagents.test | TEST | This is a warning message
2025-10-20T08:46:44.237220 | ERROR | tradingagents.test | TEST | This is an error message
2025-10-20T08:46:44.237288 | INFO | tradingagents.api | API | API call to openai/gpt-4 - success
Context: {
"call_number": 1,
"provider": "openai",
"model": "gpt-4",
"endpoint": "/v1/chat/completions",
"tokens": 150,
"cost": 0.003,
"duration_ms": 250.5,
"status": "success"
}
2025-10-20T08:46:44.237322 | ERROR | tradingagents.api | API | API call failed: Connection timeout
Context: {
"call_number": 2,
"provider": "openrouter",
"model": "llama-3",
"endpoint": "/v1/chat/completions",
"tokens": null,
"cost": null,
"duration_ms": null,
"status": "error",
"error": "Connection timeout"
}
2025-10-20T08:46:44.237362 | INFO | tradingagents.performance | PERF | analyst_execution completed in 1234.50ms
Context: {
"operation": "analyst_execution",
"duration_ms": 1234.5,
"analyst": "market"
}
2025-10-20T08:46:44.237386 | INFO | tradingagents.performance | PERF | analyst_execution completed in 987.30ms
Context: {
"operation": "analyst_execution",
"duration_ms": 987.3,
"analyst": "news"
}
2025-10-20T08:46:44.237412 | INFO | tradingagents.performance | PERF | Performance Summary
Context: {
"analyst_execution": {
"count": 2,
"avg_ms": 1110.9,
"min_ms": 987.3,
"max_ms": 1234.5
}
}

227
tradingagents/agents/utils/memory.py
View File

@ -1,10 +1,18 @@
import chromadb
from chromadb.config import Settings
from openai import OpenAI
import logging
from typing import List, Dict, Any, Optional, Tuple
import time
logger = logging.getLogger(__name__)
from tradingagents.utils.logging_config import (
get_logger,
get_api_logger,
get_performance_logger,
)
logger = get_logger("tradingagents.memory", component="MEMORY")
api_logger = get_api_logger()
perf_logger = get_performance_logger()
class FinancialSituationMemory:
@ -40,25 +48,47 @@ class FinancialSituationMemory:
self.client = None
if self.enabled and self.embedding_provider in ["openai", "ollama"]:
try:
start_time = time.time()
self.client = OpenAI(base_url=self.embedding_backend_url)
init_duration = (time.time() - start_time) * 1000
logger.info(
f"Initialized embedding client for provider: {self.embedding_provider}"
f"Initialized embedding client for '{name}'",
extra={
"context": {
"provider": self.embedding_provider,
"backend_url": self.embedding_backend_url,
"model": self.embedding_model,
"init_time_ms": init_duration,
}
},
)
perf_logger.log_timing(
"embedding_client_init",
init_duration,
{"provider": self.embedding_provider},
)
except Exception as e:
logger.warning(
f"Failed to initialize embedding client: {e}. Memory will be disabled."
f"Failed to initialize embedding client for '{name}': {e}. Memory will be disabled.",
extra={
"context": {
"provider": self.embedding_provider,
"error": str(e),
}
},
)
self.enabled = False
elif not self.enabled:
logger.info(f"Memory disabled for {name}")
logger.info(f"Memory disabled for '{name}' (enable_memory=False)")
elif self.embedding_provider == "none":
logger.info(
f"Embedding provider set to 'none'. Memory will be disabled for {name}."
f"Embedding provider set to 'none' for '{name}'. Memory will be disabled."
)
self.enabled = False
else:
logger.warning(
f"Unsupported embedding provider: {self.embedding_provider}. Memory will be disabled."
f"Unsupported embedding provider '{self.embedding_provider}' for '{name}'. Memory will be disabled."
)
self.enabled = False
@ -67,14 +97,26 @@ class FinancialSituationMemory:
self.situation_collection = None
if self.enabled:
try:
start_time = time.time()
self.chroma_client = chromadb.Client(Settings(allow_reset=True))
self.situation_collection = self.chroma_client.create_collection(
name=name
)
logger.info(f"Initialized ChromaDB collection: {name}")
init_duration = (time.time() - start_time) * 1000
logger.info(
f"Initialized ChromaDB collection '{name}'",
extra={
"context": {"collection": name, "init_time_ms": init_duration}
},
)
perf_logger.log_timing(
"chromadb_collection_init", init_duration, {"collection": name}
)
except Exception as e:
logger.error(
f"Failed to initialize ChromaDB collection: {e}. Memory will be disabled."
f"Failed to initialize ChromaDB collection '{name}': {e}. Memory will be disabled.",
extra={"context": {"collection": name, "error": str(e)}},
)
self.enabled = False
@ -108,15 +150,63 @@ class FinancialSituationMemory:
List of floats representing the embedding, or None if embedding fails
"""
if not self.enabled or not self.client:
logger.debug("Embedding skipped (memory disabled or no client)")
return None
try:
start_time = time.time()
response = self.client.embeddings.create(
model=self.embedding_model, input=text
)
return response.data[0].embedding
duration = (time.time() - start_time) * 1000
embedding = response.data[0].embedding
# Log API call
api_logger.log_call(
provider=self.embedding_provider,
model=self.embedding_model,
endpoint="embeddings.create",
tokens=len(text.split()), # Rough estimate
duration=duration,
status="success",
)
logger.debug(
f"Generated embedding for text ({len(text)} chars)",
extra={
"context": {
"provider": self.embedding_provider,
"model": self.embedding_model,
"text_length": len(text),
"duration_ms": duration,
}
},
)
return embedding
except Exception as e:
logger.error(f"Failed to get embedding: {e}")
logger.error(
f"Failed to get embedding: {e}",
extra={
"context": {
"provider": self.embedding_provider,
"model": self.embedding_model,
"text_length": len(text),
"error": str(e),
}
},
)
# Log failed API call
api_logger.log_call(
provider=self.embedding_provider,
model=self.embedding_model,
endpoint="embeddings.create",
status="error",
error=str(e),
)
return None
def add_situations(self, situations_and_advice: List[Tuple[str, str]]) -> bool:
@ -130,10 +220,19 @@ class FinancialSituationMemory:
bool: True if successful, False otherwise
"""
if not self.enabled:
logger.debug(f"Memory disabled for {self.name}, skipping add_situations")
logger.debug(
f"Memory disabled for '{self.name}', skipping add_situations",
extra={
"context": {
"collection": self.name,
"count": len(situations_and_advice),
}
},
)
return False
try:
start_time = time.time()
situations = []
advice = []
ids = []
@ -145,7 +244,14 @@ class FinancialSituationMemory:
embedding = self.get_embedding(situation)
if embedding is None:
logger.warning(
f"Failed to get embedding for situation {i}, skipping"
f"Failed to get embedding for situation {i} in '{self.name}', skipping",
extra={
"context": {
"collection": self.name,
"situation_index": i,
"situation_preview": situation[:100],
}
},
)
continue
@ -155,7 +261,15 @@ class FinancialSituationMemory:
embeddings.append(embedding)
if not situations:
logger.warning("No valid situations to add")
logger.warning(
f"No valid situations to add to '{self.name}'",
extra={
"context": {
"collection": self.name,
"attempted": len(situations_and_advice),
}
},
)
return False
self.situation_collection.add(
@ -164,11 +278,40 @@ class FinancialSituationMemory:
embeddings=embeddings,
ids=ids,
)
logger.info(f"Added {len(situations)} situations to {self.name}")
duration = (time.time() - start_time) * 1000
logger.info(
f"Added {len(situations)} situations to '{self.name}'",
extra={
"context": {
"collection": self.name,
"count": len(situations),
"total_in_collection": self.situation_collection.count(),
"duration_ms": duration,
}
},
)
perf_logger.log_timing(
"add_situations",
duration,
{"collection": self.name, "count": len(situations)},
)
return True
except Exception as e:
logger.error(f"Failed to add situations: {e}")
logger.error(
f"Failed to add situations to '{self.name}': {e}",
extra={
"context": {
"collection": self.name,
"attempted_count": len(situations_and_advice),
"error": str(e),
}
},
)
return False
def get_memories(
@ -186,14 +329,25 @@ class FinancialSituationMemory:
Returns empty list if memory is disabled or query fails.
"""
if not self.enabled:
logger.debug(f"Memory disabled for {self.name}, returning empty memories")
logger.debug(
f"Memory disabled for '{self.name}', returning empty memories",
extra={"context": {"collection": self.name}},
)
return []
try:
start_time = time.time()
query_embedding = self.get_embedding(current_situation)
if query_embedding is None:
logger.warning(
"Failed to get query embedding, returning empty memories"
f"Failed to get query embedding for '{self.name}', returning empty memories",
extra={
"context": {
"collection": self.name,
"situation_preview": current_situation[:100],
}
},
)
return []
@ -205,18 +359,51 @@ class FinancialSituationMemory:
matched_results = []
for i in range(len(results["documents"][0])):
similarity = 1 - results["distances"][0][i]
matched_results.append(
{
"matched_situation": results["documents"][0][i],
"recommendation": results["metadatas"][0][i]["recommendation"],
"similarity_score": 1 - results["distances"][0][i],
"similarity_score": similarity,
}
)
duration = (time.time() - start_time) * 1000
logger.info(
f"Retrieved {len(matched_results)} memories from '{self.name}'",
extra={
"context": {
"collection": self.name,
"requested": n_matches,
"returned": len(matched_results),
"top_similarity": matched_results[0]["similarity_score"]
if matched_results
else 0,
"duration_ms": duration,
}
},
)
perf_logger.log_timing(
"get_memories",
duration,
{"collection": self.name, "n_matches": n_matches},
)
return matched_results
except Exception as e:
logger.error(f"Failed to get memories: {e}")
logger.error(
f"Failed to get memories from '{self.name}': {e}",
extra={
"context": {
"collection": self.name,
"n_matches": n_matches,
"error": str(e),
}
},
)
return []
def is_enabled(self) -> bool:

5
tradingagents/default_config.py
View File

@ -18,6 +18,11 @@ DEFAULT_CONFIG = {
"embedding_model": "text-embedding-3-small", # Model to use for embeddings
"embedding_backend_url": "https://api.openai.com/v1", # Separate URL for embeddings
"enable_memory": True, # Set to False to disable memory/embedding features
# Logging settings
"log_level": "INFO", # Options: DEBUG, INFO, WARNING, ERROR, CRITICAL
"log_dir": "logs", # Directory for log files
"log_to_console": True, # Whether to log to console
"log_to_file": True, # Whether to log to files
# Debate and discussion settings
"max_debate_rounds": 1,
"max_risk_discuss_rounds": 1,

134
tradingagents/graph/trading_graph.py
View File

@ -5,6 +5,7 @@ from pathlib import Path
import json
from datetime import date
from typing import Dict, Any, Tuple, List, Optional
import time
from langchain_openai import ChatOpenAI
from langchain_anthropic import ChatAnthropic
@ -21,6 +22,10 @@ from tradingagents.agents.utils.agent_states import (
RiskDebateState,
)
from tradingagents.dataflows.config import set_config
from tradingagents.utils.logging_config import (
get_logger,
get_performance_logger,
)
# Import the new abstract tool methods from agent_utils
from tradingagents.agents.utils.agent_utils import (
@ -62,6 +67,23 @@ class TradingAgentsGraph:
self.debug = debug
self.config = config or DEFAULT_CONFIG
# Initialize logging
self.logger = get_logger("tradingagents.graph", component="GRAPH")
self.perf_logger = get_performance_logger()
self.logger.info(
"Initializing TradingAgentsGraph",
extra={
"context": {
"selected_analysts": selected_analysts,
"debug": debug,
"llm_provider": self.config.get("llm_provider"),
}
},
)
start_time = time.time()
# Update the interface's config
set_config(self.config)
@ -72,6 +94,18 @@ class TradingAgentsGraph:
)
# Initialize LLMs for chat (using chat model backend)
self.logger.info(
f"Initializing chat LLMs with provider: {self.config['llm_provider']}",
extra={
"context": {
"provider": self.config["llm_provider"],
"backend_url": self.config["backend_url"],
"deep_model": self.config["deep_think_llm"],
"quick_model": self.config["quick_think_llm"],
}
},
)
if (
self.config["llm_provider"].lower() == "openai"
or self.config["llm_provider"] == "ollama"
@ -100,6 +134,9 @@ class TradingAgentsGraph:
model=self.config["quick_think_llm"]
)
else:
self.logger.error(
f"Unsupported LLM provider: {self.config['llm_provider']}"
)
raise ValueError(f"Unsupported LLM provider: {self.config['llm_provider']}")
# Initialize embedding configuration (separate from chat LLM)
@ -119,11 +156,19 @@ class TradingAgentsGraph:
# Log memory status
if self.config.get("enable_memory", True):
print(
f"Memory enabled with provider: {self.config.get('embedding_provider', 'openai')}"
self.logger.info(
f"Memory enabled with provider: {self.config.get('embedding_provider', 'openai')}",
extra={
"context": {
"embedding_provider": self.config.get("embedding_provider"),
"embedding_model": self.config.get("embedding_model"),
}
},
)
else:
print("Memory disabled - agents will run without historical context")
self.logger.warning(
"Memory disabled - agents will run without historical context"
)
# Create tool nodes
self.tool_nodes = self._create_tool_nodes()
@ -154,6 +199,19 @@ class TradingAgentsGraph:
# Set up the graph
self.graph = self.graph_setup.setup_graph(selected_analysts)
init_duration = (time.time() - start_time) * 1000
self.logger.info(
f"TradingAgentsGraph initialization complete",
extra={
"context": {
"duration_ms": init_duration,
"analysts": selected_analysts,
"memory_enabled": self.config.get("enable_memory", True),
}
},
)
self.perf_logger.log_timing("graph_initialization", init_duration)
def _configure_embeddings(self):
"""Configure embedding settings, providing smart defaults based on chat LLM provider."""
# If embedding settings are not explicitly configured, set intelligent defaults
@ -229,6 +287,17 @@ class TradingAgentsGraph:
def propagate(self, company_name, trade_date):
"""Run the trading agents graph for a company on a specific date."""
self.logger.info(
f"Starting propagation for {company_name} on {trade_date}",
extra={
"context": {
"ticker": company_name,
"date": str(trade_date),
}
},
)
start_time = time.time()
self.ticker = company_name
# Initialize state
@ -237,8 +306,11 @@ class TradingAgentsGraph:
)
args = self.propagator.get_graph_args()
self.logger.debug("Starting graph execution")
if self.debug:
# Debug mode with tracing
self.logger.debug("Running in DEBUG mode with tracing")
trace = []
for chunk in self.graph.stream(init_agent_state, **args):
if len(chunk["messages"]) == 0:
@ -250,6 +322,7 @@ class TradingAgentsGraph:
final_state = trace[-1]
else:
# Standard mode without tracing
self.logger.debug("Running in standard mode")
final_state = self.graph.invoke(init_agent_state, **args)
# Store current state for reflection
@ -258,11 +331,35 @@ class TradingAgentsGraph:
# Log state
self._log_state(trade_date, final_state)
duration = (time.time() - start_time) * 1000
decision = self.process_signal(final_state["final_trade_decision"])
self.logger.info(
f"Propagation complete for {company_name}",
extra={
"context": {
"ticker": company_name,
"date": str(trade_date),
"decision": decision,
"duration_ms": duration,
}
},
)
self.perf_logger.log_timing(
"propagation",
duration,
{"ticker": company_name, "decision": decision},
)
# Return decision and processed signal
return final_state, self.process_signal(final_state["final_trade_decision"])
return final_state, decision
def _log_state(self, trade_date, final_state):
"""Log the final state to a JSON file."""
self.logger.debug(f"Logging state for {trade_date}")
self.log_states_dict[str(trade_date)] = {
"company_of_interest": final_state["company_of_interest"],
"trade_date": final_state["trade_date"],
@ -297,18 +394,25 @@ class TradingAgentsGraph:
directory = Path(f"eval_results/{self.ticker}/TradingAgentsStrategy_logs/")
directory.mkdir(parents=True, exist_ok=True)
with open(
f"eval_results/{self.ticker}/TradingAgentsStrategy_logs/full_states_log_{trade_date}.json",
"w",
) as f:
log_file = f"eval_results/{self.ticker}/TradingAgentsStrategy_logs/full_states_log_{trade_date}.json"
with open(log_file, "w") as f:
json.dump(self.log_states_dict, f, indent=4)
self.logger.debug(f"State saved to {log_file}")
def reflect_and_remember(self, returns_losses):
"""Reflect on decisions and update memory based on returns."""
if not self.config.get("enable_memory", True):
print("Memory disabled - skipping reflection and memory updates")
self.logger.info("Memory disabled - skipping reflection and memory updates")
return
self.logger.info(
f"Starting reflection and memory updates",
extra={"context": {"returns_losses": returns_losses}},
)
start_time = time.time()
self.reflector.reflect_bull_researcher(
self.curr_state, returns_losses, self.bull_memory
)
@ -325,6 +429,16 @@ class TradingAgentsGraph:
self.curr_state, returns_losses, self.risk_manager_memory
)
duration = (time.time() - start_time) * 1000
self.logger.info(
f"Reflection and memory updates complete",
extra={"context": {"duration_ms": duration}},
)
self.perf_logger.log_timing("reflect_and_remember", duration)
def process_signal(self, full_signal):
"""Process a signal to extract the core decision."""
return self.signal_processor.process_signal(full_signal)
self.logger.debug("Processing signal")
decision = self.signal_processor.process_signal(full_signal)
self.logger.debug(f"Processed signal: {decision}")
return decision

21
tradingagents/utils/__init__.py Normal file
View File

@ -0,0 +1,21 @@
"""
TradingAgents Utilities Module
Provides shared utilities including logging configuration.
"""
from .logging_config import (
get_logger,
get_api_logger,
get_performance_logger,
set_log_level,
configure_logging,
)
__all__ = [
"get_logger",
"get_api_logger",
"get_performance_logger",
"set_log_level",
"configure_logging",
]

390
tradingagents/utils/logging_config.py Normal file
View File

@ -0,0 +1,390 @@
"""
Comprehensive Logging Configuration for TradingAgents
This module provides a centralized logging system with:
- Multiple log levels (DEBUG, INFO, WARNING, ERROR, CRITICAL)
- File and console logging
- Log rotation to prevent huge files
- Structured logging with context
- Component-specific loggers
- Performance tracking
- API call tracking
"""
import logging
import logging.handlers
import sys
import os
from pathlib import Path
from datetime import datetime, timezone
from typing import Optional, Dict, Any
import json
class StructuredFormatter(logging.Formatter):
"""Custom formatter that adds structured context to log messages."""
def format(self, record: logging.LogRecord) -> str:
# Add timestamp
record.timestamp = datetime.now(timezone.utc).isoformat()
# Add component info
if not hasattr(record, "component"):
record.component = record.name.split(".")[-1]
# Format the message
formatted = super().format(record)
# Add context if available
if hasattr(record, "context") and record.context:
context_str = json.dumps(record.context, indent=2)
formatted = f"{formatted}\n Context: {context_str}"
return formatted
class TradingAgentsLogger:
"""Main logger class for TradingAgents application."""
_instance = None
_initialized = False
def __new__(cls):
if cls._instance is None:
cls._instance = super().__new__(cls)
return cls._instance
def __init__(self):
if self._initialized:
return
self.log_dir = Path("logs")
self.log_dir.mkdir(exist_ok=True)
# Create different log files for different purposes
self.log_files = {
"main": self.log_dir / "tradingagents.log",
"api": self.log_dir / "api_calls.log",
"memory": self.log_dir / "memory.log",
"agents": self.log_dir / "agents.log",
"errors": self.log_dir / "errors.log",
"performance": self.log_dir / "performance.log",
}
# Configure root logger
self._configure_root_logger()
self._initialized = True
def _configure_root_logger(self):
"""Configure the root logger with handlers and formatters."""
root_logger = logging.getLogger("tradingagents")
root_logger.setLevel(logging.DEBUG)
# Remove existing handlers to avoid duplicates
root_logger.handlers.clear()
# Console handler (INFO and above)
console_handler = logging.StreamHandler(sys.stdout)
console_handler.setLevel(logging.INFO)
console_formatter = StructuredFormatter(
"%(asctime)s | %(levelname)-8s | %(component)-15s | %(message)s",
datefmt="%Y-%m-%d %H:%M:%S",
)
console_handler.setFormatter(console_formatter)
root_logger.addHandler(console_handler)
# Main file handler (DEBUG and above) with rotation
main_handler = logging.handlers.RotatingFileHandler(
self.log_files["main"],
maxBytes=10 * 1024 * 1024, # 10 MB
backupCount=5,
)
main_handler.setLevel(logging.DEBUG)
main_formatter = StructuredFormatter(
"%(timestamp)s | %(levelname)-8s | %(name)s | %(component)s | %(message)s"
)
main_handler.setFormatter(main_formatter)
root_logger.addHandler(main_handler)
# Error file handler (ERROR and above only)
error_handler = logging.handlers.RotatingFileHandler(
self.log_files["errors"], maxBytes=5 * 1024 * 1024, backupCount=3
)
error_handler.setLevel(logging.ERROR)
error_handler.setFormatter(main_formatter)
root_logger.addHandler(error_handler)
def get_logger(self, name: str, component: Optional[str] = None) -> logging.Logger:
"""
Get a logger for a specific component.
Args:
name: Logger name (e.g., 'tradingagents.memory')
component: Component name for logging context
Returns:
Configured logger instance
"""
logger = logging.getLogger(name)
# Add component as a filter if provided
if component:
class ComponentFilter(logging.Filter):
def filter(self, record):
record.component = component
return True
logger.addFilter(ComponentFilter())
return logger
def add_file_handler(
self, logger_name: str, filename: str, level: int = logging.DEBUG
):
"""Add a dedicated file handler to a specific logger."""
logger = logging.getLogger(logger_name)
handler = logging.handlers.RotatingFileHandler(
self.log_dir / filename, maxBytes=10 * 1024 * 1024, backupCount=3
)
handler.setLevel(level)
formatter = StructuredFormatter(
"%(timestamp)s | %(levelname)-8s | %(component)s | %(message)s"
)
handler.setFormatter(formatter)
logger.addHandler(handler)
class APICallLogger:
"""Logger specifically for tracking API calls and costs."""
def __init__(self):
self.logger = get_logger("tradingagents.api", component="API")
self.call_count = 0
self.total_tokens = 0
def log_call(
self,
provider: str,
model: str,
endpoint: str,
tokens: Optional[int] = None,
cost: Optional[float] = None,
duration: Optional[float] = None,
status: str = "success",
error: Optional[str] = None,
):
"""Log an API call with details."""
self.call_count += 1
if tokens:
self.total_tokens += tokens
context = {
"call_number": self.call_count,
"provider": provider,
"model": model,
"endpoint": endpoint,
"tokens": tokens,
"cost": cost,
"duration_ms": duration,
"status": status,
}
if error:
context["error"] = error
self.logger.error(f"API call failed: {error}", extra={"context": context})
else:
self.logger.info(
f"API call to {provider}/{model} - {status}", extra={"context": context}
)
def get_stats(self) -> Dict[str, Any]:
"""Get API call statistics."""
return {"total_calls": self.call_count, "total_tokens": self.total_tokens}
class PerformanceLogger:
"""Logger for tracking performance metrics."""
def __init__(self):
self.logger = get_logger("tradingagents.performance", component="PERF")
self.timings = {}
def log_timing(
self, operation: str, duration: float, context: Optional[Dict] = None
):
"""Log operation timing."""
if operation not in self.timings:
self.timings[operation] = []
self.timings[operation].append(duration)
log_context = {"operation": operation, "duration_ms": duration}
if context:
log_context.update(context)
self.logger.info(
f"{operation} completed in {duration:.2f}ms", extra={"context": log_context}
)
def get_average_timing(self, operation: str) -> Optional[float]:
"""Get average timing for an operation."""
if operation in self.timings and self.timings[operation]:
return sum(self.timings[operation]) / len(self.timings[operation])
return None
def log_summary(self):
"""Log performance summary."""
summary = {}
for operation, timings in self.timings.items():
if timings:
summary[operation] = {
"count": len(timings),
"avg_ms": sum(timings) / len(timings),
"min_ms": min(timings),
"max_ms": max(timings),
}
self.logger.info("Performance Summary", extra={"context": summary})
# Singleton instances
_logger_instance = None
_api_logger_instance = None
_perf_logger_instance = None
def get_logger(
name: str = "tradingagents", component: Optional[str] = None
) -> logging.Logger:
"""
Get a configured logger instance.
Args:
name: Logger name
component: Component name for context
Returns:
Logger instance
"""
global _logger_instance
if _logger_instance is None:
_logger_instance = TradingAgentsLogger()
return _logger_instance.get_logger(name, component)
def get_api_logger() -> APICallLogger:
"""Get the API call logger instance."""
global _api_logger_instance
if _api_logger_instance is None:
_api_logger_instance = APICallLogger()
return _api_logger_instance
def get_performance_logger() -> PerformanceLogger:
"""Get the performance logger instance."""
global _perf_logger_instance
if _perf_logger_instance is None:
_perf_logger_instance = PerformanceLogger()
return _perf_logger_instance
def set_log_level(level: str):
"""
Set the global log level.
Args:
level: Log level ('DEBUG', 'INFO', 'WARNING', 'ERROR', 'CRITICAL')
"""
level_map = {
"DEBUG": logging.DEBUG,
"INFO": logging.INFO,
"WARNING": logging.WARNING,
"ERROR": logging.ERROR,
"CRITICAL": logging.CRITICAL,
}
log_level = level_map.get(level.upper(), logging.INFO)
logging.getLogger("tradingagents").setLevel(log_level)
def configure_logging(
level: str = "INFO", log_dir: Optional[str] = None, console: bool = True
):
"""
Configure the logging system.
Args:
level: Log level ('DEBUG', 'INFO', 'WARNING', 'ERROR', 'CRITICAL')
log_dir: Directory for log files (default: 'logs')
console: Whether to log to console
"""
global _logger_instance
if log_dir:
Path(log_dir).mkdir(parents=True, exist_ok=True)
# Initialize logger
if _logger_instance is None:
_logger_instance = TradingAgentsLogger()
# Set log level
set_log_level(level)
# Configure console logging
root_logger = logging.getLogger("tradingagents")
if not console:
# Remove console handler
root_logger.handlers = [
h for h in root_logger.handlers if not isinstance(h, logging.StreamHandler)
]
# Initialize on import
_logger_instance = TradingAgentsLogger()
if __name__ == "__main__":
# Test the logging system
print("Testing TradingAgents Logging System")
print("=" * 70)
# Get loggers
main_logger = get_logger("tradingagents.test", component="TEST")
api_logger = get_api_logger()
perf_logger = get_performance_logger()
# Test different log levels
main_logger.debug("This is a debug message")
main_logger.info("This is an info message")
main_logger.warning("This is a warning message")
main_logger.error("This is an error message")
# Test API logging
api_logger.log_call(
provider="openai",
model="gpt-4",
endpoint="/v1/chat/completions",
tokens=150,
cost=0.003,
duration=250.5,
status="success",
)
api_logger.log_call(
provider="openrouter",
model="llama-3",
endpoint="/v1/chat/completions",
status="error",
error="Connection timeout",
)
# Test performance logging
perf_logger.log_timing("analyst_execution", 1234.5, {"analyst": "market"})
perf_logger.log_timing("analyst_execution", 987.3, {"analyst": "news"})
perf_logger.log_summary()
print("\n" + "=" * 70)
print("Logging test complete. Check the 'logs' directory for output files.")
print("API Call Stats:", api_logger.get_stats())