LLM_LOGGING_GUIDE.mdā¢11.6 kB
# Detailed LLM Logging for Debugging and Statistics
## Overview
A comprehensive system for logging all LLM operations with detailed information about prompts, responses, performance, and cost savings has been implemented.
## Key Features
### š **Detailed Request Logging**
- All prompts sent to LLM
- System prompts and user instructions
- Model parameters (temperature, max tokens)
- Operation metadata (type, ID, timestamps)
### š **Response and Metrics Logging**
- Full responses from LLM models
- Token usage statistics
- Operation execution time
- Error handling with detailed information
### š° **Cost Savings Analysis**
- Cost calculation by models
- Savings from preprocessing
- Before/after token comparison
- Statistics by operation types
### š **Performance Metrics**
- Automatic statistics tracking
- Analysis by models (operation count, average tokens, time)
- Preprocessing efficiency (data reduction, savings)
- Periodic performance summaries
## Configuration
### config/default.yaml
```yaml
logging:
level: info
# Detailed LLM logging
llm:
enabled: true # enable/disable LLM logging
logPrompts: true # log all prompts
logResponses: true # log all responses
logTokens: true # log token statistics
logPerformance: true # log performance metrics
logPreprocessing: true # log preprocessing analysis
# Data logging settings
maxPromptLength: 2000 # max characters for prompts
maxResponseLength: 1000 # max characters for responses
maxInputDataLength: 5000 # max characters for input data
# Performance tracking
trackMetrics: true # track metrics
metricsInterval: 100 # log metrics every N operations
```
## Types of Logged Operations
### 1. **Content Analysis (analysis)**
```json
{
"level": "info",
"msg": "LLM Request [ANALYSIS]",
"timestamp": "2025-01-13T10:30:15.123Z",
"operationId": "op_1705135815123_1",
"operationType": "analysis",
"model": "ollama:qwen2.5:7b",
"systemPrompt": "You are an expert content analyzer...",
"userPrompt": "MAIN TASK: Extract product information...",
"maxTokens": 300,
"temperature": 0.1,
"inputDataLength": 15420,
"inputDataType": "html",
"instruction": "Extract product information as JSON"
}
```
### 2. **Preprocessing (preprocessing)**
```json
{
"level": "info",
"msg": "LLM Request [PREPROCESSING]",
"operationType": "preprocessing",
"model": "ollama:qwen2.5:7b",
"systemPrompt": "You are a data preprocessor...",
"userPrompt": "Preprocessing request: Remove HTML noise...",
"preprocessRequest": "Remove HTML noise: scripts, styles, navigation, ads, footers. Focus on product/item information, remove marketing fluff. Keep only content relevant to the main task."
}
```
### 3. **Main Processing (main)**
```json
{
"level": "info",
"msg": "LLM Request [MAIN]",
"operationType": "main",
"model": "gpt-4o-mini",
"systemPrompt": "You are a helpful assistant...",
"userPrompt": "Task: Extract product information as JSON...",
"instruction": "Extract product information as JSON",
"preprocessRequest": "Remove HTML noise: scripts, styles, navigation, ads, footers..."
}
```
## Responses and Metrics
### Successful Responses
```json
{
"level": "info",
"msg": "LLM Response [PREPROCESSING]",
"timestamp": "2025-01-13T10:30:18.456Z",
"operationId": "op_1705135815123_2",
"operationType": "preprocessing",
"model": "ollama:qwen2.5:7b",
"content": "Cleaned HTML content without navigation and ads...",
"tokensUsed": {
"prompt": 1250,
"completion": 320,
"total": 1570
},
"duration": 2847,
"success": true
}
```
### Preprocessing Analysis
```json
{
"level": "info",
"msg": "Preprocessing Analysis & Results",
"timestamp": "2025-01-13T10:30:18.500Z",
"inputData": "<html><head><script>...</script></head><body>...",
"instruction": "Extract product information as JSON",
"analysisResponse": "This HTML contains product information with navigation and ads that should be removed...",
"generatedPreprocessRequest": "Remove HTML noise: scripts, styles, navigation, ads, footers. Focus on product/item information...",
"originalLength": 15420,
"processedLength": 3200,
"reductionPercentage": "79.25",
"analysisDuration": 1500,
"preprocessingDuration": 2847,
"totalDuration": 4347
}
```
### Cost Savings Analysis
```json
{
"level": "info",
"msg": "Preprocessing Cost Analysis",
"operationId": "op_1705135815123_2",
"originalInput": "<html><head><script>...</script></head>...",
"processedInput": "Product: iPhone 15 Pro\nPrice: $999\nDescription: Latest iPhone model...",
"preprocessRequest": "Remove HTML noise: scripts, styles, navigation, ads, footers...",
"originalTokens": 3855,
"processedTokens": 800,
"tokenReduction": 3055,
"tokenReductionPercentage": "79.25",
"estimatedCostSaved": "0.0457"
}
```
## Performance Metrics
### Periodic Summaries
```json
{
"level": "info",
"msg": "LLM Performance Metrics Summary",
"timestamp": "2025-01-13T10:35:00.000Z",
"metrics": {
"totalOperations": 100,
"totalTokensUsed": 125000,
"totalCost": 0.1875,
"averageResponseTime": 2850,
"preprocessingStats": {
"count": 45,
"avgReduction": 72.3,
"avgTime": 2100
},
"modelStats": {
"gpt-4o-mini": {
"count": 55,
"avgTokens": 1200,
"avgTime": 3200,
"totalCost": 0.1250
},
"ollama:qwen2.5:7b": {
"count": 45,
"avgTokens": 800,
"avgTime": 1800,
"totalCost": 0.0000
}
}
}
}
```
### Final Summary
```json
{
"level": "info",
"msg": "Final LLM Performance Summary",
"finalMetrics": {
"totalOperations": 500,
"totalTokensUsed": 650000,
"estimatedTotalCost": 0.9750,
"averageResponseTime": 2750,
"preprocessingEffectiveness": {
"operations": 200,
"avgReduction": "75.2%",
"avgTime": 1950
},
"modelUsage": [
{
"model": "gpt-4o-mini",
"operations": 300,
"avgTokens": 1100,
"avgTime": 3100,
"totalCost": "0.7500"
},
{
"model": "ollama:qwen2.5:7b",
"operations": 200,
"avgTokens": 750,
"avgTime": 1700,
"totalCost": "0.0000"
}
]
}
}
```
## Error Handling
### LLM Request Errors
```json
{
"level": "error",
"msg": "LLM Error [ANALYSIS]",
"timestamp": "2025-01-13T10:30:15.123Z",
"operationId": "op_1705135815123_1",
"operationType": "analysis",
"model": "ollama:qwen2.5:7b",
"content": "",
"duration": 5000,
"success": false,
"error": "Connection timeout to Ollama server"
}
```
## Log Analysis
### Using grep for Analysis
```bash
# All preprocessing operations
grep '"operationType": "preprocessing"' logs/app.log
# All errors
grep '"success": false' logs/app.log
# Performance metrics
grep 'Performance Metrics Summary' logs/app.log
# Cost savings analysis
grep 'Preprocessing Cost Analysis' logs/app.log
# Statistics for specific model
grep '"model": "gpt-4o-mini"' logs/app.log
```
### Analysis with jq
```bash
# Extract all preprocessing operations
cat logs/app.log | jq 'select(.operationType == "preprocessing")'
# Token statistics
cat logs/app.log | jq 'select(.tokensUsed) | .tokensUsed.total' | awk '{sum+=$1} END {print "Total tokens:", sum}'
# Average operation duration
cat logs/app.log | jq 'select(.duration) | .duration' | awk '{sum+=$1; count++} END {print "Average duration:", sum/count, "ms"}'
# Preprocessing savings analysis
cat logs/app.log | jq 'select(.msg == "Preprocessing Cost Analysis") | .estimatedCostSaved' | awk '{sum+=$1} END {print "Total cost saved: $", sum}'
```
## Real-time Monitoring
### Viewing Logs in Real-time
```bash
# Follow all LLM operations
tail -f logs/app.log | grep -E "(LLM Request|LLM Response|Performance Metrics)"
# Follow only errors
tail -f logs/app.log | grep '"success": false'
# Follow performance metrics
tail -f logs/app.log | grep 'Performance Metrics Summary'
```
### Creating Dashboard with jq
```bash
# Simple terminal dashboard
while true; do
clear
echo "=== LLM Performance Dashboard ==="
echo "Total operations: $(grep 'LLM Request' logs/app.log | wc -l)"
echo "Total errors: $(grep '"success": false' logs/app.log | wc -l)"
echo "Preprocessing operations: $(grep '"operationType": "preprocessing"' logs/app.log | wc -l)"
echo "Average response time: $(grep 'LLM Response' logs/app.log | jq -r '.duration' | awk '{sum+=$1; count++} END {if(count>0) print sum/count "ms"; else print "N/A"}')"
sleep 5
done
```
## Logging Level Configuration
### For Debugging (Maximum Detail)
```yaml
logging:
level: debug
llm:
enabled: true
logPrompts: true
logResponses: true
logTokens: true
logPerformance: true
logPreprocessing: true
maxPromptLength: 5000 # more data for debugging
maxResponseLength: 2000
maxInputDataLength: 10000
trackMetrics: true
metricsInterval: 10 # log metrics more frequently
```
### For Production (Optimized Logging)
```yaml
logging:
level: info
llm:
enabled: true
logPrompts: false # disable prompts to save space
logResponses: false # disable responses
logTokens: true # keep tokens for monitoring
logPerformance: true # keep metrics
logPreprocessing: false # disable preprocessing details
trackMetrics: true
metricsInterval: 1000 # log metrics less frequently
```
### For Performance Analysis
```yaml
logging:
level: info
llm:
enabled: true
logPrompts: false
logResponses: false
logTokens: true
logPerformance: true
logPreprocessing: true # enable for efficiency analysis
maxPromptLength: 500 # minimal data
maxResponseLength: 200
maxInputDataLength: 1000
trackMetrics: true
metricsInterval: 50 # frequent metrics
```
## Automation Analysis
### Daily Report Script
```bash
#!/bin/bash
# daily_llm_report.sh
LOG_FILE="logs/app-$(date +%Y-%m-%d).log"
REPORT_FILE="reports/llm-$(date +%Y-%m-%d).txt"
echo "=== LLM Performance Report for $(date +%Y-%m-%d) ===" > $REPORT_FILE
# General statistics
echo "Total operations: $(grep 'LLM Request' $LOG_FILE | wc -l)" >> $REPORT_FILE
echo "Total errors: $(grep '"success": false' $LOG_FILE | wc -l)" >> $REPORT_FILE
echo "Preprocessing operations: $(grep '"operationType": "preprocessing"' $LOG_FILE | wc -l)" >> $REPORT_FILE
# Token analysis
TOTAL_TOKENS=$(grep 'LLM Response' $LOG_FILE | jq -r 'select(.tokensUsed) | .tokensUsed.total' | awk '{sum+=$1} END {print sum}')
echo "Total tokens used: $TOTAL_TOKENS" >> $REPORT_FILE
# Savings analysis
COST_SAVED=$(grep 'Preprocessing Cost Analysis' $LOG_FILE | jq -r '.estimatedCostSaved' | awk '{sum+=$1} END {print sum}')
echo "Estimated cost saved: \$${COST_SAVED}" >> $REPORT_FILE
# Average duration
AVG_DURATION=$(grep 'LLM Response' $LOG_FILE | jq -r '.duration' | awk '{sum+=$1; count++} END {if(count>0) print sum/count; else print "N/A"}')
echo "Average response time: ${AVG_DURATION}ms" >> $REPORT_FILE
echo "Report saved to $REPORT_FILE"
```
## Conclusion
The detailed LLM logging system provides:
- ā
**Full transparency** of all LLM operations
- ā
**Detailed debugging** of prompts and responses
- ā
**Performance analysis** and optimization
- ā
**Cost savings monitoring** from preprocessing
- ā
**Flexible configuration** for different needs
- ā
**Analysis automation** with standard tools
**Model:** Claude Sonnet 4