MorphGuard / src /telemetry.py
juanquy's picture
Initial clean commit of modular MorphGuard
2978bba
Raw
History Blame Contribute Delete
34.3 kB
"""
Comprehensive logging and telemetry system for MorphGuard.
This module provides centralized logging, performance metrics tracking,
and telemetry data collection for monitoring and analysis.
"""
import logging
import time
import json
import os
import sys
import socket
import uuid
import threading
import platform
import psutil
import queue
from typing import Dict, Any, Optional, List, Callable, Union
from datetime import datetime
import traceback
import atexit
from contextlib import contextmanager
from enum import Enum
# Import local error handling module
from error_handling import MGError, ErrorCode, ErrorSeverity, ErrorCategory
class LogLevel(Enum):
"""Log levels for telemetry events."""
DEBUG = "debug"
INFO = "info"
WARNING = "warning"
ERROR = "error"
CRITICAL = "critical"
class MetricType(Enum):
"""Types of metrics that can be tracked."""
COUNTER = "counter"
GAUGE = "gauge"
HISTOGRAM = "histogram"
SUMMARY = "summary"
TIMER = "timer"
class EventCategory(Enum):
"""Categories of telemetry events."""
API = "api"
AUTHENTICATION = "authentication"
DETECTION = "detection"
DEMORPHING = "demorphing"
DATABASE = "database"
FILE = "file"
MODEL = "model"
PERFORMANCE = "performance"
SECURITY = "security"
USER = "user"
SYSTEM = "system"
ERROR = "error"
class TelemetryManager:
"""
Central manager for logging, metrics, and telemetry.
This class provides:
- Structured logging with context
- Performance metrics tracking
- System resource monitoring
- Telemetry event collection
- Integration with external monitoring systems
"""
def __init__(
self,
app_name: str = "morphguard",
log_dir: Optional[str] = None,
telemetry_dir: Optional[str] = None,
log_level: int = logging.INFO,
console_logging: bool = True,
file_logging: bool = True,
json_logging: bool = False,
system_metrics_interval: int = 60,
enable_telemetry: bool = True,
max_queue_size: int = 1000,
flush_interval: int = 5,
export_metrics: bool = False,
metrics_exporter: Optional[str] = None
):
"""
Initialize the telemetry manager.
Args:
app_name: Application name for logs and metrics
log_dir: Directory to store log files
telemetry_dir: Directory to store telemetry data
log_level: Default log level
console_logging: Whether to log to console
file_logging: Whether to log to file
json_logging: Whether to use JSON format for logs
system_metrics_interval: Interval for system metrics collection in seconds
enable_telemetry: Whether to collect telemetry data
max_queue_size: Maximum size of telemetry event queue
flush_interval: Interval to flush telemetry queue in seconds
export_metrics: Whether to export metrics to external systems
metrics_exporter: Type of metrics exporter (prometheus, influxdb, etc.)
"""
self.app_name = app_name
self.log_dir = log_dir
self.telemetry_dir = telemetry_dir
self.console_logging = console_logging
self.file_logging = file_logging
self.json_logging = json_logging
self.enable_telemetry = enable_telemetry
self.export_metrics = export_metrics
self.metrics_exporter = metrics_exporter
self.max_queue_size = max_queue_size
self.flush_interval = flush_interval
# Create directories if needed
if log_dir and not os.path.exists(log_dir):
os.makedirs(log_dir)
if telemetry_dir and not os.path.exists(telemetry_dir):
os.makedirs(telemetry_dir)
# Setup main logger
self.logger = self._setup_logger(log_level)
# Metrics storage
self.metrics: Dict[str, Dict[str, Any]] = {
"counters": {},
"gauges": {},
"histograms": {},
"summaries": {},
"timers": {}
}
# Context for logs and telemetry
self.global_context: Dict[str, Any] = {
"host": socket.gethostname(),
"app_name": app_name,
"instance_id": str(uuid.uuid4()),
"platform": platform.system(),
"python_version": platform.python_version(),
"start_time": datetime.utcnow().isoformat()
}
# Thread-local storage for context
self.context = threading.local()
self.context.values = {}
# Telemetry queue and worker thread
self.telemetry_queue: queue.Queue = queue.Queue(maxsize=max_queue_size)
self.telemetry_thread: Optional[threading.Thread] = None
# System metrics thread
self.system_metrics_interval = system_metrics_interval
self.system_metrics_thread: Optional[threading.Thread] = None
# Locks
self.metrics_lock = threading.RLock()
# Start telemetry worker if enabled
if enable_telemetry:
self._start_telemetry_worker()
self._start_system_metrics_collector()
# Register cleanup on exit
atexit.register(self.shutdown)
# Log startup
self.info("Telemetry system initialized",
category=EventCategory.SYSTEM,
context={"telemetry_enabled": enable_telemetry})
def _setup_logger(self, log_level: int) -> logging.Logger:
"""
Set up the main logger.
Args:
log_level: Default log level
Returns:
Configured logger
"""
logger = logging.getLogger(self.app_name)
logger.setLevel(log_level)
logger.propagate = False
# Clear existing handlers
if logger.handlers:
for handler in logger.handlers:
logger.removeHandler(handler)
# Formatter
if self.json_logging:
formatter = self._json_formatter
else:
formatter = logging.Formatter(
'%(asctime)s [%(levelname)s] [%(name)s] %(message)s',
datefmt='%Y-%m-%d %H:%M:%S'
)
# Console handler
if self.console_logging:
console_handler = logging.StreamHandler(sys.stdout)
console_handler.setFormatter(formatter)
logger.addHandler(console_handler)
# File handler
if self.file_logging and self.log_dir:
log_file = os.path.join(self.log_dir, f"{self.app_name}.log")
file_handler = logging.FileHandler(log_file)
file_handler.setFormatter(formatter)
logger.addHandler(file_handler)
# Also create error log
error_log_file = os.path.join(self.log_dir, f"{self.app_name}_error.log")
error_handler = logging.FileHandler(error_log_file)
error_handler.setLevel(logging.ERROR)
error_handler.setFormatter(formatter)
logger.addHandler(error_handler)
return logger
def _json_formatter(self, record: logging.LogRecord) -> str:
"""
Format log record as JSON.
Args:
record: Log record to format
Returns:
JSON string
"""
timestamp = datetime.fromtimestamp(record.created).isoformat()
# Basic log data
log_data = {
"timestamp": timestamp,
"level": record.levelname,
"logger": record.name,
"message": record.getMessage(),
"module": record.module,
"function": record.funcName,
"line": record.lineno
}
# Add context if available
context = getattr(record, 'context', None)
if context:
log_data["context"] = context
# Add exception info if available
if record.exc_info:
log_data["exception"] = {
"type": record.exc_info[0].__name__,
"message": str(record.exc_info[1]),
"traceback": traceback.format_exception(*record.exc_info)
}
return json.dumps(log_data)
def _start_telemetry_worker(self) -> None:
"""Start the background telemetry worker thread."""
self.telemetry_thread = threading.Thread(
target=self._telemetry_worker,
daemon=True,
name="telemetry_worker"
)
self.telemetry_thread.start()
def _telemetry_worker(self) -> None:
"""Background worker to process and export telemetry events."""
while True:
try:
# Wait for the flush interval
time.sleep(self.flush_interval)
# Process all events in the queue
events = []
while not self.telemetry_queue.empty():
try:
event = self.telemetry_queue.get_nowait()
events.append(event)
self.telemetry_queue.task_done()
except queue.Empty:
break
if events:
self._export_events(events)
except Exception as e:
# Log the error but keep the thread running
self.logger.error(f"Error in telemetry worker: {e}", exc_info=True)
def _export_events(self, events: List[Dict[str, Any]]) -> None:
"""
Export telemetry events to storage or external systems.
Args:
events: List of telemetry events to export
"""
if not events:
return
# Save to file if telemetry directory is configured
if self.telemetry_dir:
timestamp = datetime.utcnow().strftime("%Y%m%d_%H%M%S")
file_path = os.path.join(self.telemetry_dir, f"telemetry_{timestamp}.json")
try:
with open(file_path, "w") as f:
json.dump(events, f)
except Exception as e:
self.logger.error(f"Failed to save telemetry events: {e}", exc_info=True)
# Add exporters for other systems here (e.g. Prometheus, InfluxDB, etc.)
if self.export_metrics and self.metrics_exporter:
if self.metrics_exporter.lower() == "prometheus":
self._export_to_prometheus(events)
elif self.metrics_exporter.lower() == "influxdb":
self._export_to_influxdb(events)
def _export_to_prometheus(self, events: List[Dict[str, Any]]) -> None:
"""
Export metrics to Prometheus.
Args:
events: List of telemetry events to export
"""
# Placeholder for Prometheus export
pass
def _export_to_influxdb(self, events: List[Dict[str, Any]]) -> None:
"""
Export metrics to InfluxDB.
Args:
events: List of telemetry events to export
"""
# Placeholder for InfluxDB export
pass
def _start_system_metrics_collector(self) -> None:
"""Start the background system metrics collector thread."""
self.system_metrics_thread = threading.Thread(
target=self._system_metrics_collector,
daemon=True,
name="system_metrics_collector"
)
self.system_metrics_thread.start()
def _system_metrics_collector(self) -> None:
"""Background worker to collect system metrics periodically."""
while True:
try:
# Collect system metrics
self._collect_system_metrics()
# Wait for the next collection interval
time.sleep(self.system_metrics_interval)
except Exception as e:
# Log the error but keep the thread running
self.logger.error(f"Error in system metrics collector: {e}", exc_info=True)
time.sleep(self.system_metrics_interval)
def _collect_system_metrics(self) -> None:
"""Collect system metrics and record them."""
try:
# CPU usage
cpu_percent = psutil.cpu_percent(interval=1)
self.gauge("system.cpu.percent", cpu_percent)
# Memory usage
memory = psutil.virtual_memory()
self.gauge("system.memory.total", memory.total)
self.gauge("system.memory.available", memory.available)
self.gauge("system.memory.used", memory.used)
self.gauge("system.memory.percent", memory.percent)
# Disk usage
disk = psutil.disk_usage('/')
self.gauge("system.disk.total", disk.total)
self.gauge("system.disk.used", disk.used)
self.gauge("system.disk.free", disk.free)
self.gauge("system.disk.percent", disk.percent)
# Network IO
net_io = psutil.net_io_counters()
self.gauge("system.network.bytes_sent", net_io.bytes_sent)
self.gauge("system.network.bytes_recv", net_io.bytes_recv)
# Process metrics
process = psutil.Process()
self.gauge("process.cpu_percent", process.cpu_percent(interval=1))
self.gauge("process.memory.rss", process.memory_info().rss)
self.gauge("process.memory.vms", process.memory_info().vms)
self.gauge("process.threads", process.num_threads())
self.gauge("process.open_files", len(process.open_files()))
# Add telemetry event
self.telemetry(
EventCategory.SYSTEM,
"system_metrics_collected",
level=LogLevel.DEBUG,
data={
"cpu_percent": cpu_percent,
"memory_percent": memory.percent,
"disk_percent": disk.percent,
"process_cpu_percent": process.cpu_percent(interval=0)
}
)
except Exception as e:
self.logger.error(f"Failed to collect system metrics: {e}", exc_info=True)
def set_context(self, **kwargs) -> None:
"""
Set context values for the current thread.
Args:
**kwargs: Key-value pairs to add to the context
"""
if not hasattr(self.context, 'values'):
self.context.values = {}
for key, value in kwargs.items():
self.context.values[key] = value
def clear_context(self, *keys) -> None:
"""
Clear context values for the current thread.
Args:
*keys: Keys to clear. If none provided, clears all context.
"""
if not hasattr(self.context, 'values'):
return
if not keys:
# Clear all context
self.context.values = {}
else:
# Clear specific keys
for key in keys:
if key in self.context.values:
del self.context.values[key]
def get_context(self) -> Dict[str, Any]:
"""
Get the current thread's context combined with global context.
Returns:
Combined context dictionary
"""
context = self.global_context.copy()
# Add thread local context if available
if hasattr(self.context, 'values'):
context.update(self.context.values)
return context
def _add_log_context(self, extra: Optional[Dict[str, Any]] = None) -> Dict[str, Any]:
"""
Prepare log record extra with context.
Args:
extra: Additional extra data for the log record
Returns:
Combined extra dictionary with context
"""
result = {'context': self.get_context()}
if extra:
# If context is provided in extra, merge it with the existing context
if 'context' in extra:
result['context'].update(extra.pop('context'))
# Add remaining extra fields
result.update(extra)
return result
def debug(self, message: str, category: Optional[EventCategory] = None,
context: Optional[Dict[str, Any]] = None, **kwargs) -> None:
"""
Log a debug message.
Args:
message: Log message
category: Event category
context: Additional context for this log
**kwargs: Additional data for the log record
"""
extra = self._add_log_context(kwargs)
if context:
extra['context'].update(context)
if category:
extra['context']['category'] = category.value
self.logger.debug(message, extra=extra)
def info(self, message: str, category: Optional[EventCategory] = None,
context: Optional[Dict[str, Any]] = None, **kwargs) -> None:
"""
Log an info message.
Args:
message: Log message
category: Event category
context: Additional context for this log
**kwargs: Additional data for the log record
"""
extra = self._add_log_context(kwargs)
if context:
extra['context'].update(context)
if category:
extra['context']['category'] = category.value
self.logger.info(message, extra=extra)
def warning(self, message: str, category: Optional[EventCategory] = None,
context: Optional[Dict[str, Any]] = None, **kwargs) -> None:
"""
Log a warning message.
Args:
message: Log message
category: Event category
context: Additional context for this log
**kwargs: Additional data for the log record
"""
extra = self._add_log_context(kwargs)
if context:
extra['context'].update(context)
if category:
extra['context']['category'] = category.value
self.logger.warning(message, extra=extra)
def error(self, message: str, category: Optional[EventCategory] = None,
context: Optional[Dict[str, Any]] = None, exc_info: bool = True, **kwargs) -> None:
"""
Log an error message.
Args:
message: Log message
category: Event category
context: Additional context for this log
exc_info: Whether to include exception info
**kwargs: Additional data for the log record
"""
extra = self._add_log_context(kwargs)
if context:
extra['context'].update(context)
if category:
extra['context']['category'] = category.value
self.logger.error(message, exc_info=exc_info, extra=extra)
# Also send an error telemetry event
if self.enable_telemetry:
error_data = {
"message": message,
"context": extra.get('context', {})
}
if exc_info and sys.exc_info()[0] is not None:
error_type = sys.exc_info()[0].__name__
error_message = str(sys.exc_info()[1])
error_data["exception"] = {
"type": error_type,
"message": error_message
}
self.telemetry(
EventCategory.ERROR if not category else category,
"error",
level=LogLevel.ERROR,
data=error_data
)
def critical(self, message: str, category: Optional[EventCategory] = None,
context: Optional[Dict[str, Any]] = None, exc_info: bool = True, **kwargs) -> None:
"""
Log a critical message.
Args:
message: Log message
category: Event category
context: Additional context for this log
exc_info: Whether to include exception info
**kwargs: Additional data for the log record
"""
extra = self._add_log_context(kwargs)
if context:
extra['context'].update(context)
if category:
extra['context']['category'] = category.value
self.logger.critical(message, exc_info=exc_info, extra=extra)
# Also send a critical telemetry event
if self.enable_telemetry:
error_data = {
"message": message,
"context": extra.get('context', {})
}
if exc_info and sys.exc_info()[0] is not None:
error_type = sys.exc_info()[0].__name__
error_message = str(sys.exc_info()[1])
error_data["exception"] = {
"type": error_type,
"message": error_message
}
self.telemetry(
EventCategory.ERROR if not category else category,
"critical_error",
level=LogLevel.CRITICAL,
data=error_data
)
def log_error(self, error: Union[MGError, Exception], category: Optional[EventCategory] = None,
context: Optional[Dict[str, Any]] = None) -> None:
"""
Log an error object.
Args:
error: Error object to log
category: Event category
context: Additional context for this log
"""
if isinstance(error, MGError):
# Use the error's severity to determine log level
if error.severity == ErrorSeverity.DEBUG:
log_func = self.debug
elif error.severity == ErrorSeverity.INFO:
log_func = self.info
elif error.severity == ErrorSeverity.WARNING:
log_func = self.warning
elif error.severity == ErrorSeverity.CRITICAL:
log_func = self.critical
else:
log_func = self.error
# Determine category
if not category:
# Map error category to event category
if error.category == ErrorCategory.API:
event_category = EventCategory.API
elif error.category == ErrorCategory.AUTHENTICATION:
event_category = EventCategory.AUTHENTICATION
elif error.category == ErrorCategory.FILE:
event_category = EventCategory.FILE
elif error.category == ErrorCategory.MODEL:
event_category = EventCategory.MODEL
elif error.category == ErrorCategory.DATABASE:
event_category = EventCategory.DATABASE
else:
event_category = EventCategory.ERROR
else:
event_category = category
# Prepare context
error_context = {}
if context:
error_context.update(context)
error_context.update({
"error_code": error.code,
"error_category": error.category
})
if error.details:
error_context["error_details"] = error.details
# Log the error
log_func(
f"[{error.code}] {error.message}",
category=event_category,
context=error_context,
exc_info=True
)
else:
# Regular exception
self.error(
str(error),
category=category or EventCategory.ERROR,
context=context,
exc_info=True
)
def counter(self, name: str, value: int = 1, tags: Optional[Dict[str, str]] = None) -> None:
"""
Increment a counter metric.
Args:
name: Metric name
value: Value to increment by
tags: Tags for the metric
"""
with self.metrics_lock:
if name not in self.metrics["counters"]:
self.metrics["counters"][name] = {
"value": 0,
"created_at": time.time(),
"tags": tags or {}
}
# Increment counter
self.metrics["counters"][name]["value"] += value
self.metrics["counters"][name]["updated_at"] = time.time()
# Update tags if provided
if tags:
self.metrics["counters"][name]["tags"].update(tags)
def gauge(self, name: str, value: float, tags: Optional[Dict[str, str]] = None) -> None:
"""
Set a gauge metric.
Args:
name: Metric name
value: Gauge value
tags: Tags for the metric
"""
with self.metrics_lock:
# Update or create gauge
self.metrics["gauges"][name] = {
"value": value,
"updated_at": time.time(),
"tags": tags or {}
}
if "created_at" not in self.metrics["gauges"][name]:
self.metrics["gauges"][name]["created_at"] = time.time()
def histogram(self, name: str, value: float, tags: Optional[Dict[str, str]] = None) -> None:
"""
Add a value to a histogram metric.
Args:
name: Metric name
value: Value to add
tags: Tags for the metric
"""
with self.metrics_lock:
if name not in self.metrics["histograms"]:
self.metrics["histograms"][name] = {
"count": 0,
"sum": 0,
"min": float('inf'),
"max": float('-inf'),
"values": [],
"created_at": time.time(),
"tags": tags or {}
}
# Update histogram
self.metrics["histograms"][name]["count"] += 1
self.metrics["histograms"][name]["sum"] += value
self.metrics["histograms"][name]["min"] = min(
self.metrics["histograms"][name]["min"], value
)
self.metrics["histograms"][name]["max"] = max(
self.metrics["histograms"][name]["max"], value
)
self.metrics["histograms"][name]["values"].append(value)
self.metrics["histograms"][name]["updated_at"] = time.time()
# Keep only the last 1000 values to limit memory usage
if len(self.metrics["histograms"][name]["values"]) > 1000:
self.metrics["histograms"][name]["values"].pop(0)
# Update tags if provided
if tags:
self.metrics["histograms"][name]["tags"].update(tags)
def timer(self, name: str, duration: float, tags: Optional[Dict[str, str]] = None) -> None:
"""
Record a timing metric.
Args:
name: Metric name
duration: Duration in seconds
tags: Tags for the metric
"""
# Timers are implemented as histograms
self.histogram(name, duration, tags)
@contextmanager
def timing(self, name: str, tags: Optional[Dict[str, str]] = None) -> None:
"""
Context manager for timing a block of code.
Args:
name: Metric name
tags: Tags for the metric
Yields:
None
"""
start_time = time.time()
try:
yield
finally:
duration = time.time() - start_time
self.timer(name, duration, tags)
def summary(self, name: str, value: float, tags: Optional[Dict[str, str]] = None) -> None:
"""
Update a summary metric.
Args:
name: Metric name
value: Value to add
tags: Tags for the metric
"""
with self.metrics_lock:
if name not in self.metrics["summaries"]:
self.metrics["summaries"][name] = {
"count": 0,
"sum": 0,
"created_at": time.time(),
"tags": tags or {}
}
# Update summary
self.metrics["summaries"][name]["count"] += 1
self.metrics["summaries"][name]["sum"] += value
self.metrics["summaries"][name]["updated_at"] = time.time()
# Update tags if provided
if tags:
self.metrics["summaries"][name]["tags"].update(tags)
def get_metrics(self) -> Dict[str, Any]:
"""
Get all metrics.
Returns:
Dictionary with all metrics
"""
with self.metrics_lock:
return {
"counters": self.metrics["counters"].copy(),
"gauges": self.metrics["gauges"].copy(),
"histograms": self.metrics["histograms"].copy(),
"summaries": self.metrics["summaries"].copy()
}
def get_metric(self, name: str, metric_type: MetricType) -> Optional[Dict[str, Any]]:
"""
Get a specific metric.
Args:
name: Metric name
metric_type: Metric type
Returns:
Metric data or None if not found
"""
with self.metrics_lock:
if metric_type == MetricType.COUNTER:
return self.metrics["counters"].get(name)
elif metric_type == MetricType.GAUGE:
return self.metrics["gauges"].get(name)
elif metric_type == MetricType.HISTOGRAM:
return self.metrics["histograms"].get(name)
elif metric_type == MetricType.SUMMARY:
return self.metrics["summaries"].get(name)
elif metric_type == MetricType.TIMER:
return self.metrics["histograms"].get(name) # Timers are stored as histograms
else:
return None
def reset_metrics(self) -> None:
"""Reset all metrics."""
with self.metrics_lock:
self.metrics = {
"counters": {},
"gauges": {},
"histograms": {},
"summaries": {}
}
def telemetry(
self,
category: EventCategory,
event_type: str,
level: LogLevel = LogLevel.INFO,
data: Optional[Dict[str, Any]] = None
) -> None:
"""
Submit a telemetry event.
Args:
category: Event category
event_type: Type of event
level: Log level for the event
data: Event data
"""
if not self.enable_telemetry:
return
event = {
"category": category.value,
"type": event_type,
"level": level.value,
"timestamp": datetime.utcnow().isoformat(),
"context": self.get_context()
}
if data:
event["data"] = data
try:
# Don't block if queue is full
self.telemetry_queue.put(event, block=False)
except queue.Full:
self.logger.warning("Telemetry queue is full, event dropped")
def shutdown(self) -> None:
"""Shutdown the telemetry system and flush pending events."""
if self.enable_telemetry:
# Flush telemetry queue
self.logger.info("Shutting down telemetry system")
try:
events = []
while not self.telemetry_queue.empty():
try:
event = self.telemetry_queue.get_nowait()
events.append(event)
self.telemetry_queue.task_done()
except queue.Empty:
break
if events:
self._export_events(events)
except Exception as e:
self.logger.error(f"Error during telemetry shutdown: {e}", exc_info=True)
# Create a singleton instance
_instance = None
def get_telemetry(
app_name: str = "morphguard",
log_dir: Optional[str] = None,
telemetry_dir: Optional[str] = None,
log_level: int = logging.INFO,
console_logging: bool = True,
file_logging: bool = True,
enable_telemetry: bool = True
) -> TelemetryManager:
"""
Get the global telemetry manager instance.
Args:
app_name: Application name
log_dir: Directory for log files
telemetry_dir: Directory for telemetry data
log_level: Default log level
console_logging: Whether to log to console
file_logging: Whether to log to file
enable_telemetry: Whether to enable telemetry
Returns:
TelemetryManager instance
"""
global _instance
if _instance is None:
_instance = TelemetryManager(
app_name=app_name,
log_dir=log_dir,
telemetry_dir=telemetry_dir,
log_level=log_level,
console_logging=console_logging,
file_logging=file_logging,
enable_telemetry=enable_telemetry
)
return _instance