feat: create v2-prep branch with comprehensive planning
Restructured project for V2 refactor: **Structure Changes:** - Moved all V1 code to orig/ folder (preserved with git mv) - Created docs/planning/ directory - Added orig/README_V1.md explaining V1 preservation **Planning Documents:** - 00_V2_MASTER_PLAN.md: Complete architecture overview - Executive summary of critical V1 issues - High-level component architecture diagrams - 5-phase implementation roadmap - Success metrics and risk mitigation - 07_TASK_BREAKDOWN.md: Atomic task breakdown - 99+ hours of detailed tasks - Every task < 2 hours (atomic) - Clear dependencies and success criteria - Organized by implementation phase **V2 Key Improvements:** - Per-exchange parsers (factory pattern) - Multi-layer strict validation - Multi-index pool cache - Background validation pipeline - Comprehensive observability **Critical Issues Addressed:** - Zero address tokens (strict validation + cache enrichment) - Parsing accuracy (protocol-specific parsers) - No audit trail (background validation channel) - Inefficient lookups (multi-index cache) - Stats disconnection (event-driven metrics) Next Steps: 1. Review planning documents 2. Begin Phase 1: Foundation (P1-001 through P1-010) 3. Implement parsers in Phase 2 4. Build cache system in Phase 3 5. Add validation pipeline in Phase 4 6. Migrate and test in Phase 5 🤖 Generated with [Claude Code](https://claude.com/claude-code) Co-Authored-By: Claude <noreply@anthropic.com>
This commit is contained in:
Administrator
484
orig/internal/logger/logger.go
Normal file
484
orig/internal/logger/logger.go
Normal file
@@ -0,0 +1,484 @@
|
||||
package logger
|
||||
|
||||
import (
|
||||
"fmt"
|
||||
"log"
|
||||
"os"
|
||||
"path/filepath"
|
||||
"strings"
|
||||
"time"
|
||||
|
||||
pkgerrors "github.com/fraktal/mev-beta/pkg/errors"
|
||||
)
|
||||
|
||||
// LogLevel represents different log levels
|
||||
type LogLevel int
|
||||
|
||||
const (
|
||||
DEBUG LogLevel = iota
|
||||
INFO
|
||||
WARN
|
||||
ERROR
|
||||
OPPORTUNITY // Special level for opportunities
|
||||
)
|
||||
|
||||
var logLevelNames = map[LogLevel]string{
|
||||
DEBUG: "DEBUG",
|
||||
INFO: "INFO",
|
||||
WARN: "WARN",
|
||||
ERROR: "ERROR",
|
||||
OPPORTUNITY: "OPPORTUNITY",
|
||||
}
|
||||
|
||||
var suppressedWarningSubstrings = []string{
|
||||
"extractTokensGeneric",
|
||||
"extractTokensFromMulticall",
|
||||
}
|
||||
|
||||
// Logger represents a multi-file logger with separation of concerns
|
||||
type Logger struct {
|
||||
// Main application logger
|
||||
logger *log.Logger
|
||||
level LogLevel
|
||||
|
||||
// Specialized loggers for different concerns
|
||||
opportunityLogger *log.Logger // MEV opportunities and arbitrage attempts
|
||||
errorLogger *log.Logger // Errors and warnings only
|
||||
performanceLogger *log.Logger // Performance metrics and RPC calls
|
||||
transactionLogger *log.Logger // Detailed transaction analysis
|
||||
|
||||
// Security filtering
|
||||
secureFilter *SecureFilter
|
||||
|
||||
levelName string
|
||||
}
|
||||
|
||||
// parseLogLevel converts string log level to LogLevel enum
|
||||
func parseLogLevel(level string) LogLevel {
|
||||
switch strings.ToLower(level) {
|
||||
case "debug":
|
||||
return DEBUG
|
||||
case "info":
|
||||
return INFO
|
||||
case "warn", "warning":
|
||||
return WARN
|
||||
case "error":
|
||||
return ERROR
|
||||
default:
|
||||
return INFO // Default to INFO level
|
||||
}
|
||||
}
|
||||
|
||||
// createLogFile creates a log file or returns stdout if it fails
|
||||
func createLogFile(filename string) *os.File {
|
||||
if filename == "" {
|
||||
return os.Stdout
|
||||
}
|
||||
|
||||
if err := os.MkdirAll(filepath.Dir(filename), 0o755); err != nil {
|
||||
log.Printf("Failed to create log directory for %s: %v, falling back to stdout", filename, err)
|
||||
return os.Stdout
|
||||
}
|
||||
|
||||
// Check and rotate log file if needed (100MB max size)
|
||||
maxSize := int64(100 * 1024 * 1024) // 100 MB
|
||||
if err := rotateLogFile(filename, maxSize); err != nil {
|
||||
log.Printf("Failed to rotate log file %s: %v", filename, err)
|
||||
// Continue anyway, rotation failure shouldn't stop logging
|
||||
}
|
||||
|
||||
f, err := os.OpenFile(filename, os.O_CREATE|os.O_WRONLY|os.O_APPEND, 0600)
|
||||
if err != nil {
|
||||
log.Printf("Failed to create log file %s: %v, falling back to stdout", filename, err)
|
||||
return os.Stdout
|
||||
}
|
||||
return f
|
||||
}
|
||||
|
||||
// New creates a new multi-file logger with separation of concerns
|
||||
func New(level string, format string, file string) *Logger {
|
||||
// Parse base filename for specialized logs
|
||||
baseDir := "logs"
|
||||
baseName := "mev_bot"
|
||||
if file != "" {
|
||||
// Extract directory and base filename
|
||||
parts := strings.Split(file, "/")
|
||||
if len(parts) > 1 {
|
||||
baseDir = strings.Join(parts[:len(parts)-1], "/")
|
||||
}
|
||||
filename := parts[len(parts)-1]
|
||||
if strings.Contains(filename, ".") {
|
||||
baseName = strings.Split(filename, ".")[0]
|
||||
}
|
||||
}
|
||||
|
||||
// Create specialized log files
|
||||
mainFile := createLogFile(file)
|
||||
opportunityFile := createLogFile(fmt.Sprintf("%s/%s_opportunities.log", baseDir, baseName))
|
||||
errorFile := createLogFile(fmt.Sprintf("%s/%s_errors.log", baseDir, baseName))
|
||||
performanceFile := createLogFile(fmt.Sprintf("%s/%s_performance.log", baseDir, baseName))
|
||||
transactionFile := createLogFile(fmt.Sprintf("%s/%s_transactions.log", baseDir, baseName))
|
||||
|
||||
// Create loggers with no prefixes (we format ourselves)
|
||||
logLevel := parseLogLevel(level)
|
||||
|
||||
// Determine security level based on environment and log level
|
||||
var securityLevel SecurityLevel
|
||||
env := os.Getenv("GO_ENV")
|
||||
switch {
|
||||
case env == "production":
|
||||
securityLevel = SecurityLevelProduction
|
||||
case logLevel >= WARN:
|
||||
securityLevel = SecurityLevelInfo
|
||||
default:
|
||||
securityLevel = SecurityLevelDebug
|
||||
}
|
||||
|
||||
return &Logger{
|
||||
logger: log.New(mainFile, "", 0),
|
||||
opportunityLogger: log.New(opportunityFile, "", 0),
|
||||
errorLogger: log.New(errorFile, "", 0),
|
||||
performanceLogger: log.New(performanceFile, "", 0),
|
||||
transactionLogger: log.New(transactionFile, "", 0),
|
||||
level: logLevel,
|
||||
secureFilter: NewSecureFilter(securityLevel),
|
||||
levelName: level,
|
||||
}
|
||||
}
|
||||
|
||||
// shouldLog determines if a message should be logged based on level
|
||||
func (l *Logger) shouldLog(level LogLevel) bool {
|
||||
return level >= l.level
|
||||
}
|
||||
|
||||
// formatMessage formats a log message with timestamp and level
|
||||
func (l *Logger) formatMessage(level LogLevel, v ...interface{}) string {
|
||||
timestamp := time.Now().Format("2006/01/02 15:04:05")
|
||||
levelName := logLevelNames[level]
|
||||
message := formatKVMessage(v...)
|
||||
return fmt.Sprintf("%s [%s] %s", timestamp, levelName, message)
|
||||
}
|
||||
|
||||
// formatKVMessage converts a variadic list of arguments into a structured log string.
|
||||
// It treats consecutive key/value pairs (string key followed by any value) specially
|
||||
// so that existing logger calls like logger.Error("msg", "key", value) render as
|
||||
// `msg key=value`.
|
||||
func formatKVMessage(args ...interface{}) string {
|
||||
if len(args) == 0 {
|
||||
return ""
|
||||
}
|
||||
|
||||
var b strings.Builder
|
||||
|
||||
// Always print the first argument verbatim to preserve legacy formatting.
|
||||
fmt.Fprintf(&b, "%v", args[0])
|
||||
|
||||
// Process subsequent arguments as key/value pairs where possible.
|
||||
for i := 1; i < len(args); i++ {
|
||||
key, ok := args[i].(string)
|
||||
if !ok || i == len(args)-1 {
|
||||
// Not a key/value pair, fall back to simple spacing.
|
||||
fmt.Fprintf(&b, " %v", args[i])
|
||||
continue
|
||||
}
|
||||
|
||||
value := args[i+1]
|
||||
fmt.Fprintf(&b, " %s=%v", key, value)
|
||||
i++
|
||||
}
|
||||
|
||||
return b.String()
|
||||
}
|
||||
|
||||
// Debug logs a debug message
|
||||
func (l *Logger) Debug(v ...interface{}) {
|
||||
if l.shouldLog(DEBUG) {
|
||||
l.logger.Println(l.formatMessage(DEBUG, v...))
|
||||
}
|
||||
}
|
||||
|
||||
// Info logs an info message
|
||||
func (l *Logger) Info(v ...interface{}) {
|
||||
if l.shouldLog(INFO) {
|
||||
l.logger.Println(l.formatMessage(INFO, v...))
|
||||
}
|
||||
}
|
||||
|
||||
// Warn logs a warning message
|
||||
func (l *Logger) Warn(v ...interface{}) {
|
||||
if l.shouldLog(WARN) {
|
||||
message := l.formatMessage(WARN, v...)
|
||||
for _, substr := range suppressedWarningSubstrings {
|
||||
if strings.Contains(message, substr) {
|
||||
return
|
||||
}
|
||||
}
|
||||
l.logger.Println(message)
|
||||
l.errorLogger.Println(message) // Also log to error file
|
||||
}
|
||||
}
|
||||
|
||||
// Error logs an error message
|
||||
func (l *Logger) Error(v ...interface{}) {
|
||||
if l.shouldLog(ERROR) {
|
||||
message := l.formatMessage(ERROR, v...)
|
||||
l.logger.Println(message)
|
||||
l.errorLogger.Println(message) // Also log to error file
|
||||
}
|
||||
}
|
||||
|
||||
// ErrorStructured logs a structured error with full context
|
||||
func (l *Logger) ErrorStructured(err *pkgerrors.StructuredError) {
|
||||
if !l.shouldLog(ERROR) {
|
||||
return
|
||||
}
|
||||
|
||||
// Log compact format to main log
|
||||
compactMsg := fmt.Sprintf("%s [%s] %s",
|
||||
time.Now().Format("2006/01/02 15:04:05"),
|
||||
"ERROR",
|
||||
err.FormatCompact())
|
||||
l.logger.Println(compactMsg)
|
||||
|
||||
// Log full detailed format to error log
|
||||
fullMsg := fmt.Sprintf("%s [%s] %s",
|
||||
time.Now().Format("2006/01/02 15:04:05"),
|
||||
"ERROR",
|
||||
err.FormatForLogging())
|
||||
l.errorLogger.Println(fullMsg)
|
||||
}
|
||||
|
||||
// WarnStructured logs a structured warning with full context
|
||||
func (l *Logger) WarnStructured(err *pkgerrors.StructuredError) {
|
||||
if !l.shouldLog(WARN) {
|
||||
return
|
||||
}
|
||||
|
||||
// Log compact format to main log
|
||||
compactMsg := fmt.Sprintf("%s [%s] %s",
|
||||
time.Now().Format("2006/01/02 15:04:05"),
|
||||
"WARN",
|
||||
err.FormatCompact())
|
||||
|
||||
// Check if warning should be suppressed
|
||||
for _, substr := range suppressedWarningSubstrings {
|
||||
if strings.Contains(compactMsg, substr) {
|
||||
return
|
||||
}
|
||||
}
|
||||
|
||||
l.logger.Println(compactMsg)
|
||||
l.errorLogger.Println(compactMsg)
|
||||
}
|
||||
|
||||
// Opportunity logs a found opportunity with detailed information
|
||||
// This always logs regardless of level since opportunities are critical
|
||||
func (l *Logger) Opportunity(txHash, from, to, method, protocol string, amountIn, amountOut, minOut, profitUSD float64, additionalData map[string]interface{}) {
|
||||
timestamp := time.Now().Format("2006/01/02 15:04:05")
|
||||
|
||||
// Create sanitized additional data for production
|
||||
sanitizedData := l.secureFilter.SanitizeForProduction(additionalData)
|
||||
|
||||
message := fmt.Sprintf(`%s [OPPORTUNITY] 🎯 ARBITRAGE OPPORTUNITY DETECTED
|
||||
├── Transaction: %s
|
||||
├── From: %s → To: %s
|
||||
├── Method: %s (%s)
|
||||
├── Amount In: %.6f tokens
|
||||
├── Amount Out: %.6f tokens
|
||||
├── Min Out: %.6f tokens
|
||||
├── Estimated Profit: $%.2f USD
|
||||
└── Additional Data: %v`,
|
||||
timestamp, txHash, from, to, method, protocol,
|
||||
amountIn, amountOut, minOut, profitUSD, sanitizedData)
|
||||
|
||||
// Apply security filtering to the entire message
|
||||
filteredMessage := l.secureFilter.FilterMessage(message)
|
||||
|
||||
l.logger.Println(filteredMessage)
|
||||
l.opportunityLogger.Println(filteredMessage) // Dedicated opportunity log
|
||||
}
|
||||
|
||||
// OpportunitySimple logs a simple opportunity message (for backwards compatibility)
|
||||
func (l *Logger) OpportunitySimple(v ...interface{}) {
|
||||
timestamp := time.Now().Format("2006/01/02 15:04:05")
|
||||
message := fmt.Sprintf("%s [OPPORTUNITY] %s", timestamp, fmt.Sprint(v...))
|
||||
l.logger.Println(message)
|
||||
l.opportunityLogger.Println(message) // Dedicated opportunity log
|
||||
}
|
||||
|
||||
// Performance logs performance metrics for optimization analysis
|
||||
func (l *Logger) Performance(component, operation string, duration time.Duration, metadata map[string]interface{}) {
|
||||
timestamp := time.Now().Format("2006/01/02 15:04:05")
|
||||
|
||||
// Add standard performance fields
|
||||
data := map[string]interface{}{
|
||||
"component": component,
|
||||
"operation": operation,
|
||||
"duration_ms": duration.Milliseconds(),
|
||||
"duration_ns": duration.Nanoseconds(),
|
||||
"timestamp": timestamp,
|
||||
}
|
||||
|
||||
// Merge with provided metadata
|
||||
for k, v := range metadata {
|
||||
data[k] = v
|
||||
}
|
||||
|
||||
message := fmt.Sprintf(`%s [PERFORMANCE] 📊 %s.%s completed in %v - %v`,
|
||||
timestamp, component, operation, duration, data)
|
||||
|
||||
l.performanceLogger.Println(message) // Dedicated performance log only
|
||||
}
|
||||
|
||||
// Metrics logs business metrics for analysis
|
||||
func (l *Logger) Metrics(name string, value float64, unit string, tags map[string]string) {
|
||||
timestamp := time.Now().Format("2006/01/02 15:04:05")
|
||||
|
||||
message := fmt.Sprintf(`%s [METRICS] 📈 %s: %.6f %s %v`,
|
||||
timestamp, name, value, unit, tags)
|
||||
|
||||
l.performanceLogger.Println(message) // Metrics go to performance log
|
||||
}
|
||||
|
||||
// Transaction logs detailed transaction information for MEV analysis
|
||||
func (l *Logger) Transaction(txHash, from, to, method, protocol string, gasUsed, gasPrice uint64, value float64, success bool, metadata map[string]interface{}) {
|
||||
timestamp := time.Now().Format("2006/01/02 15:04:05")
|
||||
|
||||
status := "FAILED"
|
||||
if success {
|
||||
status = "SUCCESS"
|
||||
}
|
||||
|
||||
// Sanitize metadata for production
|
||||
sanitizedMetadata := l.secureFilter.SanitizeForProduction(metadata)
|
||||
|
||||
message := fmt.Sprintf(`%s [TRANSACTION] 💳 %s
|
||||
├── Hash: %s
|
||||
├── From: %s → To: %s
|
||||
├── Method: %s (%s)
|
||||
├── Gas Used: %d (Price: %d wei)
|
||||
├── Value: %.6f ETH
|
||||
├── Status: %s
|
||||
└── Metadata: %v`,
|
||||
timestamp, status, txHash, from, to, method, protocol,
|
||||
gasUsed, gasPrice, value, status, sanitizedMetadata)
|
||||
|
||||
// Apply security filtering to the entire message
|
||||
filteredMessage := l.secureFilter.FilterMessage(message)
|
||||
|
||||
l.transactionLogger.Println(filteredMessage) // Dedicated transaction log only
|
||||
}
|
||||
|
||||
// BlockProcessing logs block processing metrics for sequencer monitoring
|
||||
func (l *Logger) BlockProcessing(blockNumber uint64, txCount, dexTxCount int, processingTime time.Duration) {
|
||||
timestamp := time.Now().Format("2006/01/02 15:04:05")
|
||||
|
||||
message := fmt.Sprintf(`%s [BLOCK_PROCESSING] 🧱 Block %d: %d txs (%d DEX) processed in %v`,
|
||||
timestamp, blockNumber, txCount, dexTxCount, processingTime)
|
||||
|
||||
l.performanceLogger.Println(message) // Block processing metrics go to performance log
|
||||
}
|
||||
|
||||
// ArbitrageAnalysis logs arbitrage opportunity analysis results
|
||||
func (l *Logger) ArbitrageAnalysis(poolA, poolB, tokenPair string, priceA, priceB, priceDiff, estimatedProfit float64, feasible bool) {
|
||||
timestamp := time.Now().Format("2006/01/02 15:04:05")
|
||||
|
||||
status := "REJECTED"
|
||||
if feasible {
|
||||
status = "VIABLE"
|
||||
}
|
||||
|
||||
message := fmt.Sprintf(`%s [ARBITRAGE_ANALYSIS] 🔍 %s %s
|
||||
├── Pool A: %s (Price: %.6f)
|
||||
├── Pool B: %s (Price: %.6f)
|
||||
├── Price Difference: %.4f%%
|
||||
├── Estimated Profit: $%.2f
|
||||
└── Status: %s`,
|
||||
timestamp, status, tokenPair, poolA, priceA, poolB, priceB,
|
||||
priceDiff*100, estimatedProfit, status)
|
||||
|
||||
// Apply security filtering to protect sensitive pricing data
|
||||
filteredMessage := l.secureFilter.FilterMessage(message)
|
||||
|
||||
l.opportunityLogger.Println(filteredMessage) // Arbitrage analysis goes to opportunity log
|
||||
}
|
||||
|
||||
// RPC logs RPC call metrics for endpoint optimization
|
||||
func (l *Logger) RPC(endpoint, method string, duration time.Duration, success bool, errorMsg string) {
|
||||
timestamp := time.Now().Format("2006/01/02 15:04:05")
|
||||
|
||||
status := "SUCCESS"
|
||||
if !success {
|
||||
status = "FAILED"
|
||||
}
|
||||
|
||||
message := fmt.Sprintf(`%s [RPC] 🌐 %s %s.%s in %v`,
|
||||
timestamp, status, endpoint, method, duration)
|
||||
|
||||
if !success && errorMsg != "" {
|
||||
message += fmt.Sprintf(" - Error: %s", errorMsg)
|
||||
}
|
||||
|
||||
l.performanceLogger.Println(message) // RPC metrics go to performance log
|
||||
}
|
||||
|
||||
// SwapAnalysis logs swap event analysis with security filtering
|
||||
func (l *Logger) SwapAnalysis(tokenIn, tokenOut string, amountIn, amountOut float64, protocol, poolAddr string, metadata map[string]interface{}) {
|
||||
timestamp := time.Now().Format("2006/01/02 15:04:05")
|
||||
|
||||
// Sanitize metadata for production
|
||||
sanitizedMetadata := l.secureFilter.SanitizeForProduction(metadata)
|
||||
|
||||
message := fmt.Sprintf(`%s [SWAP_ANALYSIS] 🔄 %s → %s
|
||||
├── Amount In: %.6f %s
|
||||
├── Amount Out: %.6f %s
|
||||
├── Protocol: %s
|
||||
├── Pool: %s
|
||||
└── Metadata: %v`,
|
||||
timestamp, tokenIn, tokenOut, amountIn, tokenIn, amountOut, tokenOut,
|
||||
protocol, poolAddr, sanitizedMetadata)
|
||||
|
||||
// Apply security filtering to the entire message
|
||||
filteredMessage := l.secureFilter.FilterMessage(message)
|
||||
|
||||
l.transactionLogger.Println(filteredMessage) // Dedicated transaction log
|
||||
}
|
||||
|
||||
// rotateLogFile rotates a log file when it exceeds the maximum size
|
||||
func rotateLogFile(filename string, maxSize int64) error {
|
||||
// Check if file exists
|
||||
if _, err := os.Stat(filename); os.IsNotExist(err) {
|
||||
return nil // File doesn't exist, nothing to rotate
|
||||
}
|
||||
|
||||
// Get file info
|
||||
fileInfo, err := os.Stat(filename)
|
||||
if err != nil {
|
||||
return fmt.Errorf("failed to get file info: %w", err)
|
||||
}
|
||||
|
||||
// Check if file exceeds max size
|
||||
if fileInfo.Size() < maxSize {
|
||||
return nil // File is within size limits
|
||||
}
|
||||
|
||||
// Create archive directory if it doesn't exist
|
||||
archiveDir := "logs/archived"
|
||||
if err := os.MkdirAll(archiveDir, 0755); err != nil {
|
||||
return fmt.Errorf("failed to create archive directory: %w", err)
|
||||
}
|
||||
|
||||
// Generate archive filename with timestamp
|
||||
timestamp := time.Now().Format("20060102_150405")
|
||||
baseName := filepath.Base(filename)
|
||||
ext := filepath.Ext(baseName)
|
||||
name := strings.TrimSuffix(baseName, ext)
|
||||
archiveFilename := filepath.Join(archiveDir, fmt.Sprintf("%s_%s%s", name, timestamp, ext))
|
||||
|
||||
// Close current file handle and rename
|
||||
if err := os.Rename(filename, archiveFilename); err != nil {
|
||||
return fmt.Errorf("failed to rotate log file: %w", err)
|
||||
}
|
||||
|
||||
return nil
|
||||
}
|
||||
Reference in New Issue
Block a user